X-Git-Url: https://git.llucax.com/software/sercom-old.git/blobdiff_plain/727acb5562491fcd2ffb88d31caec867e7dbef49..4d996d9a8b118836ad4de537ead8144b78bf530f:/src/sc_test?ds=sidebyside diff --git a/src/sc_test b/src/sc_test index c06f4e9..5643e61 100755 --- a/src/sc_test +++ b/src/sc_test @@ -4,36 +4,32 @@ # Módulos estándar import os -import sys import pwd import time import signal -import locale +import glob import shutil import datetime -import logging -import logging.config import subprocess -import ConfigParser -# Módulos externos -import sqlobject +import email.MIMEMultipart # Módulos locales -from sercom.dbo import * +import sercom +import sercom.sqlo +from sercom.sqlo import * -class secure: +class secure_process: def __init__(self, chroot, uid, gid, cpu): self.chroot = chroot self.uid = uid self.gid = gid self.cpu = cpu def __call__(self): - def x2(val): - return (val, val) from os import chroot, setuid, setgid import resource chroot(self.chroot) setgid(self.gid) setuid(self.uid) + x2 = lambda val: (val, val) # Devuelve una tupla con val 2 veces resource.setrlimit(resource.RLIMIT_AS, x2(20*1024*1024)) resource.setrlimit(resource.RLIMIT_CORE, x2(0)) resource.setrlimit(resource.RLIMIT_CPU, x2(self.cpu)) @@ -43,67 +39,368 @@ class secure: resource.setrlimit(resource.RLIMIT_MEMLOCK, x2(100)) resource.setrlimit(resource.RLIMIT_NOFILE, x2(100)) resource.setrlimit(resource.RLIMIT_NPROC, x2(0)) - -def logger(): - log = None - for log_conf in ('log.ini', os.path.expanduser('~/.sercom/log.ini'), '/etc/sercom/log.ini'): - if (os.access(log_conf, os.R_OK)): - logging.config.fileConfig(log_conf) - log = logging.getLogger('test') - return log + # Tratamos de forzar un sync para que entre al sleep del padre + time.sleep(0) def sigchld(signum, frame): """Signal handler para SIGCHILD.""" - #global hijo_muerto - #hijo_muerto = True - pass + global hijo_muerto, log + log.debug('Murió el hijo') + hijo_muerto = True def sigterm(signum, frame): """Signal handler para SIGTERM y SIGINT.""" global continuar, log continuar = False log.debug('Señal %d recibida', signum) + log.info('Finalizado') + +def compilar(intento, mail): + global log + # Busco makefile + makefile = os.path.join(intento.entrega.ejercicio.path, 'Makefile') + # Compilo + log.debug('Ejecutando: make -f %s', makefile) + intento.inicioCompila = datetime.datetime.now() + stderr = file(os.path.join(intento.path, 'make.out'), 'w') + make = subprocess.Popen(('make', '-f', makefile), stderr=stderr, + cwd=intento.path) + make.wait() + intento.finCompila = datetime.datetime.now() + log.debug('Fin del comando: make -f %s', makefile) + # Verifico compilación + stderr = file(os.path.join(intento.path, 'make.out')).read() + intento.compila = not make.returncode + msg = 'Compilación: ' + if intento.compila and not stderr: + msg += 'BIEN' + elif intento.compila: + msg += 'CON ADVERTENCIAS' + else: + msg += 'ERROR (código de retorno: %d)' % make.returncode + mail.body += msg + if stderr: + msg += ''' +Salida: +------------------------------------------------------------------------ +%s +------------------------------------------------------------------------ +''' % stderr + mail.body += "\n(se adjunta salida, archivo 'make.stderr')\n" + mail.attachText(stderr, 'make.stderr') + mail.body += '\n\n' + intento.observaciones = msg + '\n\n' + log.debug(msg) -# Seteo locale -locale.setlocale(locale.LC_ALL, '') +def preparar(intento, caso_de_prueba): + # Creo chroot - TODO copiarlo de algún lado donde ande el valgrind? + os.makedirs(intento.chrootPath(caso_de_prueba)) + shutil.copy(os.path.join(intento.path, 'tp'), + os.path.join(intento.chrootPath(caso_de_prueba), 'tp')) -# Obtengo configuración -conf = ConfigParser.SafeConfigParser() -if not conf.read(('/etc/sercom/sercom.ini', os.path.expanduser('~/.sercom/sercom.ini'), 'sercom.ini')): - sys.stderr.write('No se pudo obtener configuración!\n') - sys.exit(1) +def limpiar(intento, caso_de_prueba): + # Borro chroot entero + #shutil.rmtree(intento.chrootPath) + os.unlink(os.path.join(intento.chrootPath(caso_de_prueba), 'tp')) -# Obtengo id de usuario con el cual ejecutar las pruebas -(uid, gid) = pwd.getpwnam(conf.get('general', 'user'))[2:4] +def probar(intento, caso_de_prueba, mail): + def diff(prueba, mail, orig, new, name, origname='alumno', newname='catedra', longname=None): + from difflib import unified_diff, HtmlDiff + if longname is None: longname = name + diff = ''.join(list(unified_diff(orig, new, fromfile=name+'.'+origname, tofile=name+'.'+newname))) + nota = '' + if diff: + prueba.pasada = False + nota += "* %s no coincide con lo esperado (archivo '%s.diff').\n" % (longname, name) + nota += ('-' * 72) + '\n' + diff + ('-' * 72) + '\n' + if not prueba.casoDePrueba.privado: + mail.attachText(diff, name + '.diff') + diff = HtmlDiff().make_file(orig, new, fromdesc=name+'.'+origname, todesc=name+'.'+newname, context=True, numlines=3) + mail.attachText(diff, name + '.diff.html', 'html') + return nota + def usa_stdin(): + return os.path.exists(os.path.join(caso_de_prueba.path, 'stdin')) + def usa_stdout(): + return os.path.exists(os.path.join(caso_de_prueba.path, 'stdout')) + def usa_stderr(): + return os.path.exists(os.path.join(caso_de_prueba.path, 'stderr')) -# Cambio UID efectivo -os.seteuid(uid) + # Cosas útiles + global log, conn, conf, uid, gid + # Para manejo de SIGCHLD + global hijo_muerto + hijo_muerto = False + # Obtengo datos útiles del caso de prueba + tiempo_cpu = caso_de_prueba.tiempoCpu + if tiempo_cpu is None: + tiempo_cpu = conf.get('general', 'tiempo_cpu') + tiempo_cpu = int(tiempo_cpu) + # Creo prueba nueva + prueba = Prueba(intento=intento, casoDePrueba=caso_de_prueba, + inicio=datetime.datetime.now(), connection=conn) + log.debug('Iniciando prueba: %s', prueba) + log.debug('Caso de prueba: %s', prueba.casoDePrueba) + # Abro archivos para fds básicos + options = { + 'cwd': intento.chrootPath(caso_de_prueba), + 'close_fds': True, + 'preexec_fn': secure_process(intento.chrootPath(caso_de_prueba), uid, gid, tiempo_cpu), + 'stdin': None, + 'stdout': None, + 'stderr': None, + } + if usa_stdin(): + options['stdin'] = file(os.path.join(caso_de_prueba.path, 'stdin'), 'r') + if usa_stdout(): + stdout_fn = intento.chrootPath(caso_de_prueba) + '.stdout' + options['stdout'] = file(stdout_fn, 'w') + if usa_stderr(): + stderr_fn = intento.chrootPath(caso_de_prueba) + '.stderr' + options['stderr'] = file(stderr_fn, 'w') + # Ejecuto programa + params = ['/tp'] + if caso_de_prueba.parametros: + params += params2seq(caso_de_prueba.parametros) + log.debug('Ejecutando %s', ' '.join(params)) + os.seteuid(0) # Dios! (para chroot) + try: + proc = subprocess.Popen(params, **options) + except Exception, e: # FIXME poner en el manejo de exceptiones estandar + try: + log.debug('ERROR! Trace del hijo: %s', e.child_traceback) + raise + except: + raise + os.seteuid(uid) # Mortal de nuevo + if not hijo_muerto: # Recibido por el sigchld, para saber si murió + time.sleep(tiempo_cpu) # Controlo que no tarde mucho + # Si el proceso sigue andando lo tenemos que matar + if not hijo_muerto: + log.debug('La prueba tardó más del tiempo permitido (%d segundos)', + tiempo_cpu) + os.seteuid(0) # Dios! (corre como Dios, hay que matarlo como Dios) + os.kill(proc.pid, signal.SIGKILL) + os.seteuid(uid) # Mortal de nuevo + log.debug('Prueba cancelada (kill)') + proc.wait() + prueba.observaciones = 'Excedió el límite de tiempo de ejecución ' \ + '(%d seg)' % tiempo_cpu + prueba.fin = datetime.datetime.now() + prueba.pasada = False + mail.agregarResultado(prueba) + return prueba + proc.wait() # Para que no queden zombies + prueba.fin = datetime.datetime.now() + # Salió con una señal? + if proc.returncode < 0: + sig = -proc.returncode + # Conversor de nro de señal a string + sigs = {} + for s in [s for s in dir(signal) if s.startswith('SIG') and s.isalpha()]: + sigs[getattr(signal, s)] = s + log.debug('El programa salió con la señal %s', sigs[sig]) + prueba.pasada = False + #TODO otras señales conocidas + if sig == signal.SIGXCPU: + prueba.observaciones = 'Excedió el límite de tiempo de CPU ' \ + '(%d seg)' % tiempo_cpu + else: + prueba.observaciones = 'Salió con la señal %s' % sigs[sig] + mail.agregarResultado(prueba) + return prueba + # Si tenemos que verificar el código de retorno + if caso_de_prueba.codigoRetorno is not None: + #FIXME trucho lo de 256 + # Si el código de error esperado es 256 => el código de error debe ser != 0 + # Si no el código de error esperado debe ser igual al obtenido + if caso_de_prueba.codigoRetorno != proc.returncode \ + or caso_de_prueba.codigoRetorno == 256 \ + and proc.returncode != 0: + log.debug('Código de retorno incorrecto (debía ser %d y se obtuvo %d)', + caso_de_prueba.codigoRetorno, proc.returncode) + prueba.pasada = False + prueba.observaciones = 'Código de retorno incorrecto (debía ' \ + 'ser %d y se obtuvo %d)' % (caso_de_prueba.codigoRetorno, + proc.returncode) + mail.agregarResultado(prueba) + return prueba + # Verifico salidas estándar/de error + prueba.pasada = True # Asumo que está bien, ya habrá tiempo para cambiarlo + obs = '' + if usa_stdout(): + obs += diff(prueba, mail, file(stdout_fn).readlines(), + file(os.path.join(caso_de_prueba.path, 'stdout')).readlines(), + caso_de_prueba.nombre + '.stdout', longname='La salida estándar') + if usa_stderr(): + obs += diff(prueba, mail, file(stderr_fn).readlines(), + file(os.path.join(caso_de_prueba.path, 'stderr')).readlines(), + caso_de_prueba.nombre + '.stderr', longname='La salida de error') + for f in caso_de_prueba.archivosSalida: + if f not in prueba.archivosSalida: + log.debug('Falta el archivo %s y no lo hizo.', f) + prueba.pasada = False + obs += "* Falta el archivo de salida '%s'.\n" % f + continue + obs += diff(prueba, mail, + file(os.path.join(intento.chrootPath(caso_de_prueba), f)).readlines(), + file(os.path.join(caso_de_prueba.pathSalidas, f)).readlines(), + caso_de_prueba.nombre + '.' + f) + for f in prueba.archivosSalida - (caso_de_prueba.archivosSalida | caso_de_prueba.archivosEntrada): + log.debug('El programa debía generar el archivo %s y no lo hizo.', f) + prueba.pasada = False + obs += "* Se generó un archivo ('%s') que no se esperaba.\n" % f + log.debug('Fin de ejecución de caso de prueba (hijo: %d, ret: %d)', + proc.pid, proc.returncode) + if obs: + prueba.observaciones = obs + mail.agregarResultado(prueba) + log.debug('Resultado de la prueba: %s', prueba) + return prueba -# Seteo umask para que el grupo pueda leer -os.umask(00027) +def params2seq(params): + r"""Parsea un string de forma similar al bash, separando por espacios y + teniendo en cuenta comillas simples y dobles para agrupar. Para poner + comillas se puede usar el \ como caracter de escape (\' y \") y también + interpreta \n y \t. Devuelve una lista con los parámetros encontrados.""" + # Constantes + SEP, TOKEN, DQUOTE, SQUOTE = ' ', None, '"', "'" + seq = [] + buff = '' + escape = False + state = SEP + for c in params: + # Es un caracter escapado + if escape: + if c == 'n': + buff += '\n' + elif c == 't': + buff += '\t' + else: + buff += c + escape = False + continue + # Es una secuencia de escape + if c == '\\': + escape = True + continue + # Si está buscando espacios + if state == SEP: + if c == SEP: + continue + else: + state = TOKEN # Encontró + if state == TOKEN: + if c == DQUOTE: + state = DQUOTE + continue + if c == SQUOTE: + state = SQUOTE + continue + if c == SEP: + state = SEP + seq.append(buff) + buff = '' + continue + buff += c + continue + if state == DQUOTE: + if c == DQUOTE: + state = TOKEN + continue + buff += c + continue + if state == SQUOTE: + if c == SQUOTE: + state = TOKEN + continue + buff += c + continue + raise Exception, 'No tiene sentido' + if state == DQUOTE or state == SQUOTE: + raise Exception, 'Parse error, falta cerrar comilla (%s)' % state + if buff: + seq.append(buff) + return seq -# Conecto señales -signal.signal(signal.SIGCHLD, sigchld) +class MailIntento(email.MIMEMultipart.MIMEMultipart, object): + def __init__(self, intento): + global conf + from email.MIMEMultipart import MIMEMultipart + from email.MIMEMessage import MIMEMessage + from email.MIMEText import MIMEText + MIMEMultipart.__init__(self) + self.subject = '[%s] Resultado del intento %d (ejercicio %d.%d)' % \ + (conf.get('mail', 'prefijo'), intento.numero, + intento.entrega.nroEjercicio, intento.entrega.entrega) + self['From'] = conf.get('mail', 'from') + self['To'] = intento.mailRespuesta + self['Reply-To'] = conf.get('mail', 'admin') + self['Return-Path'] = conf.get('mail', 'admin') + self['X-Mailer'] = 'sercom ' + sercom.VERSION + self['X-Priority'] = '5' + self.epilogue = 'Para ver correctamente este e-mail su cliente debe ' \ + 'soportar MIME.\n\n' + self.prologue = '' # Garantiza que termine en \n el mensaje + self.attach(MIMEMessage(MIMEText('', 'plain', 'iso-8859-1'))) + self.resultado = None + def __set_body(self, body): + self.get_payload(0).get_payload(0).set_payload(body) + def __get_body(self): + return self.get_payload(0).get_payload(0).get_payload() + body = property(__get_body, __set_body, doc='Cuerpo del mensaje.') + def attachText(self, text, nombre=None, subtype='plain'): + from email.MIMEText import MIMEText + attach = MIMEText(text, subtype, 'iso-8859-1') + if nombre: + attach.add_header('Content-Disposition', 'attachment', filename=nombre) + self.attach(attach) + def send(self, resultado=None): + import smtplib + global conf + smtp = smtplib.SMTP(conf.get('mail', 'smtp')) + if resultado: + self.subject += ': ' + resultado + self['Subject'] = self.subject + smtp.sendmail(self['From'], self['To'], self.as_string()) + smtp.close() + def agregarResultado(self, prueba): + if not prueba.casoDePrueba.privado: + if prueba.pasada: + result = 'BIEN' + else: + result = 'ERROR' + self.body += ''' +Prueba '%s': %s +%s +''' % (prueba.casoDePrueba.nombre, result, prueba.observaciones or '') + pass + + +# Manejadores de señales signal.signal(signal.SIGTERM, sigterm) signal.signal(signal.SIGINT, sigterm) +signal.signal(signal.SIGCHLD, sigchld) +hijo_muerto = False # Cambia con SIGCHLD +continuar = True # Cambia con SIGTERM o SIGINT -# Conexión a la DB -conn = sqlobject.connectionForURI(conf.get('dbo', 'database')) - -# Cargo config del logger -log = logger() -if not log: - print >>sys.stderr, 'No se pudo cargar archivo de configuración de log.' - sys.exit(1) +# Inicializo +conf, conn, log = sercom.init('test') log.info('Iniciado') -# Algunas variables de configuración útiles -data_dir = conf.get('general', 'data_dir') +# Obtengo id de usuario con el cual ejecutar las pruebas +uid, gid = pwd.getpwnam(conf.get('general', 'user'))[2:4] + +# Cambio UID efectivo +os.seteuid(uid) + +# Atajo intervalo = float(conf.get('general', 'intervalo')) +# Utilizo el directorio de datos como base para todos los SQLObjects +sercom.sqlo.dir_base = conf.get('general', 'data_dir') + # Hasta que nos maten -continuar = True # Cambia con una señal while continuar: # Busco intento a probar intento = Intento.getProximoAProbar(conn) @@ -111,129 +408,44 @@ while continuar: log.debug('No hay intento para probar') time.sleep(intervalo) continue - log.info('Nuevo intento a probar (%s)', intento) - # Obtengo paths - intento_dir = os.path.join(data_dir, intento.path('intentos')) - entrega_dir = os.path.join(data_dir, 'ejercicios', str(intento.entrega.ejercicioID)) - print entrega_dir - # Busco makefile - makefile = os.path.join(entrega_dir, 'Makefile') - if not os.path.exists(makefile): - makefile = os.path.join(data_dir, 'Makefile') - shutil.copy(makefile, intento_dir) - # Compilo - log.debug('Ejecutando: make -f %s', makefile) - intento.inicioCompila = datetime.datetime.now() - make = subprocess.Popen(('make', '-f', makefile), stdout=subprocess.PIPE, - stderr=subprocess.PIPE, cwd=intento_dir) - make.wait() - intento.finCompila = datetime.datetime.now() - log.debug('Fin del comando: make -f %s', makefile) - # Verifico compilación - if make.returncode: - log.debug('Error al compilar, código de retorno: %d, salida estándar: ' - '%s, salida de error: %s)', make.returncode, make.stdout.read(), - make.stderr.read()) - intento.compila = False - #TODO enviar_respuesta(R_ERR, $mail, "ERROR AL COMPILAR!\n\n$err\n\nCódigo de retorno: $ret\n", $intento); - continue; - else: - log.debug('Compilado OK') - intento.compila = True - #TODO mail acumulativo - # Creo chroot - TODO copiarlo de algún lado donde ande el valgrind? - chroot_dir = os.path.join(intento_dir, 'chroot') - ejecutable = os.path.join(chroot_dir, 'tp') - os.mkdir(chroot_dir) - shutil.move(os.path.join(intento_dir, 'tp'), ejecutable) - # Cambio permisos - XXX al pedo? Hice seteuid() - os.chmod(chroot_dir, 02770) - os.chown(chroot_dir, uid, gid) - os.chmod(ejecutable, 0550) - os.chown(ejecutable, uid, gid) + log.info('Nuevo intento a probar (%d %d.%d.%d %d%d%d [%d %d %d])', + intento.inscripto.padron, intento.entrega.nroEjercicio, + intento.entrega.entrega, intento.numero, intento.entrega.curso.anio, + intento.entrega.curso.cuatrimestre, intento.entrega.curso.curso, + intento.inscripto.id, intento.entrega.id, intento.id) + mail = MailIntento(intento) + # Compila + compilar(intento, mail) + if not intento.compila: + log.info('Intento[%d] no compila', intento.id) + mail.send('NO COMPILA') + continue # Ejecución de casos de prueba intento.inicioPruebas = datetime.datetime.now() + resultado = True for caso_de_prueba in intento.entrega.ejercicio.casosDePrueba: - # Obtengo datos útiles del caso de prueba - tiempo_cpu = caso_de_prueba.tiempoCpu - if tiempo_cpu is None: - tiempo_cpu = conf.get('general', 'tiempo_cpu') - tiempo_cpu = int(tiempo_cpu) - # Creo prueba nueva - prueba = Prueba(intento=intento, casoDePrueba=caso_de_prueba, - inicio=datetime.datetime.now(), connection = conn) - log.debug('Prueba: %s', prueba) - # Abro archivos para fds básicos - #XXX sacar nombres de archivos de prueba???? - #stdin = file(os.path.join(intento_dir, 'stdin'), 'r') - stdout = file(os.path.join(intento_dir, 'stdout'), 'w') - stderr = file(os.path.join(intento_dir, 'stderr'), 'w') - # Ejecuto programa - log.debug('Ejecutando /tp %s', caso_de_prueba.parametros) - os.seteuid(0) # Dios! (para chroot) - # FIXME caso_de_prueba.parametros - try: - proc = subprocess.Popen('/tp', stdout=stdout, stderr=stderr, #stdin=stdin, - preexec_fn=secure(chroot_dir, uid, gid, tiempo_cpu)) - except Exception, e: # FIXME poner en el manejo de exceptiones estandar - try: - print e, e.child_traceback - except: - print e - os.seteuid(uid) # Mortal de nuevo - time.sleep(tiempo_cpu) - # Si el proceso sigue andando lo tenemos que matar - if proc.poll() is None: - log.debug('La prueba tardó más del tiempo permitido (%d segundos)', - tiempo_cpu) - os.seteuid(0) # Dios! (corre como Dios, hay que matarlo como Dios) - os.kill(proc.pid, signal.SIGKILL) - os.seteuid(uid) # Mortal de nuevo - log.debug('Prueba cancelada (kill)') - proc.wait() - prueba.observaciones = 'Excedió el límite de tiempo de ejecución ' \ - '(%d seg)' % tiempo_cpu - prueba.fin = datetime.datetime.now() - prueba.pasada = False - continue - proc.wait() # Para que no queden zombies - prueba.fin = str(datetime.datetime.now()) - # Salió con una señal? - if proc.returncode < 0: - sig = -proc.returncode - log.debug('El programa salió con la señal %d', sig) - prueba.pasada = False - #TODO otras señales conocidas - if sig == signal.SIGXCPU: - prueba.observaciones = 'Excedió el límite de tiempo de CPU ' \ - '(%d seg)' % tiempo_cpu - else: - prueba.observaciones = 'Salió con la señal %d' % sig - continue - # Si tenemos que verificar el código de retorno - if caso_de_prueba.codigoRetorno is not None: - #FIXME trucho lo de 256 - # Si el código de error esperado es 256 => el código de error debe ser != 0 - # Si no el código de error esperado debe ser igual al obtenido - if caso_de_prueba.codigoRetorno != proc.returncode \ - or caso_de_prueba.codigoRetorno == 256 \ - and proc.returncode != 0: - log.debug('Código de retorno incorrecto (debía ser %d y se obtuvo %d)', - caso_de_prueba.codigoRetorno, proc.returncode) - prueba.pasada = False - prueba.observaciones = 'Código de retorno incorrecto (debía ' \ - 'ser %d y se obtuvo %d)' % (caso_de_prueba.codigoRetorno, - proc.returncode) - #TODO verificar salidas, hacer diff - log.debug('Fin de ejecución de caso de prueba (hijo: %d, ret: %d)', - proc.pid, proc.returncode) - prueba.pasada = True - log.debug('Prueba OK: %s', prueba) + # Preparo chroot + preparar(intento, caso_de_prueba) + # Pruebo y agrego prueba a la lista + prueba = probar(intento, caso_de_prueba, mail) + if not prueba.casoDePrueba.privado and not prueba.pasada: + log.info('Prueba %s[%d %d] no pasada', prueba.casoDePrueba.nombre, + prueba.casoDePrueba.id, prueba.id) + resultado = False + # Limpio chroot + limpiar(intento, caso_de_prueba) intento.finPruebas = datetime.datetime.now() - #TODO make clean - #TODO Armar mail de respuesta al alumno - for prueba in Prueba.selectBy(intentoID=intento.id, connection=conn): - #TODO Si es publica, veo si se hizo ok o no y voy creando mail - pass - time.sleep(intervalo) + # Envío mail con resultado al alumno + if resultado: + mail.send('ACEPTADO') + log.info('Pruebas finalizadas (intento[%d] aceptado)', intento.id) + else: + mail.send('FALLA PRUEBAS') + log.info('Pruebas finalizadas (intento[%d] no aceptado)', intento.id) + # Limpio directorio + log.debug('Borrando ejecutable y código objeto (*.o)') + os.remove(os.path.join(intento.path, 'tp')) + for obj in glob.glob(os.path.join(intento.path, '*.o')): + os.remove(obj) + # time.sleep(intervalo) #XXX Puede servir para enlentecer el server