- logging in serve.py replaced prints

- more widespread logging - added issues in BUGS.md

- logging in serve.py replaced prints
- more widespread logging - added issues in BUGS.md
Miguel Barão
1 parent 4da6fa98
Showing 4 changed files with 87 additions and 46 deletions Show diff stats
BUGS.md
questions.py
serve.py
test.py
 # BUGS
+- cherrypy faz logs para consola...
+- mensagens info nao aparecem no serve.py
+- usar thread.Lock para aceder a variaveis de estado.
+- ordenar activos por hora de login.
+- se no teste uma das "ref" nao existir nos ficheiros de perguntas, rebenta.
+- no final do teste (em modo avaliacao) o aluno é removido da lista allowed. para fazer novamente necessita de aprovação do professor.
 - mesmo aluno pode entrar várias vezes em simultaneo...
-- ordenar lista de alunos pelos online/offline, e depois pelo numero.
 - qd scripts não são executáveis rebenta. Testar isso e dar uma mensagem de erro.
 - paths manipulation in strings is unix only ('/something'). use os.path to create paths.
 - alunos vêm nota final arredondada às decimas, mas é apenas um arredondamento visual. Pode acontecer o aluno chumbar, mas ver uma nota positiva (e.g.  9.46 mostra 9.5 e presume que esta aprovado). Mostrar 3 casas?
@@ -15,6 +20,10 @@
 # TODO
+- script de correcção pode enviar dicionario yaml com grade e comentarios. ex:
+    grade: 0.5
+    comments: Falhou na função xpto.
+    os comentários são guardados no teste (ficheiro) ou enviados para o browser no modo practice.
 - warning quando se executa novamente o mesmo teste na consola. ie se ja houver submissoes desse teste.
 - na cotacao da pergunta indicar o intervalo, e.g.  [-0.2, 1],  [0, 0.5]
 - fazer uma calculadora javascript e por no menu. surge como modal
@@ -32,6 +41,7 @@
 # FIXED
+- ordenar lista de alunos pelos online/offline, e depois pelo numero.
 - hash das passwords concatenadas com salt gerado aleatoriamente. necessario acrescentar salt de cada aluno. gerar salt com os.urandom(256)
 - fix ans directory. relative to what?? current dir?
 - textarea com opcao de numero de linhas (consoante o programa a desenvolver podem ser necessarias mais ou menos linhas)
@@ -38,27 +38,29 @@ import os.path
 import logging
 import sys
-try:
-    import yaml
-except ImportError:
-    print('The package "yaml" is missing. See README.md for instructions.')
-    sys.exit(1)
-qlogger = logging.getLogger('Questions')
+qlogger = logging.getLogger('questions')
 qlogger.setLevel(logging.INFO)
 fh = logging.FileHandler('question.log')
 ch = logging.StreamHandler()
 ch.setLevel(logging.INFO)
-formatter = logging.Formatter('%(asctime)s | %(name)s | %(levelname)s | %(message)s')
+formatter = logging.Formatter('%(asctime)s | %(name)-10s | %(levelname)-8s | %(message)s')
 fh.setFormatter(formatter)
 ch.setFormatter(formatter)
 qlogger.addHandler(fh)
 qlogger.addHandler(ch)
+try:
+    import yaml
+except ImportError:
+    logger.critical('The package "yaml" is missing. See README.md for instructions.')
+    sys.exit(1)
+
+
 # if an error occurs in a question, the question is replaced by this message
 qerror = {
     'filename': 'questions.py',
@@ -112,7 +114,7 @@ class QuestionsPool(dict):
                 qlogger.error('Error loading questions from YAML file "{0}". Skipping this one.'.format(filename))
                 continue
             self.add(questions, filename, path)
-            qlogger.info('Added {0} questions from "{1}" to the pool.'.format(len(questions), filename))
+            qlogger.info('Loaded {0} questions from "{1}".'.format(len(questions), filename))
 #============================================================================
@@ -7,6 +7,7 @@
 from os import path
 import sys
 import argparse
+import logging
 # from threading import Lock
 try:
@@ -31,6 +32,13 @@ import test
 import database
+ch = logging.StreamHandler()
+ch.setLevel(logging.INFO)
+ch.setFormatter(logging.Formatter('%(asctime)s | %(name)-10s | %(levelname)-8s | %(message)s'))
+
+logger = logging.getLogger('serve')
+logger.addHandler(ch)
+
 # ============================================================================
 #   Classes that respond to HTTP
@@ -198,25 +206,35 @@ def parse_arguments():
 # ============================================================================
 if __name__ == '__main__':
+
+    logger.error('---------- Running perguntations ----------')
+
     # --- parse command line arguments and build base test
     arg = parse_arguments()
     testconf = test.read_configuration(arg.testfile[0], debug=arg.debug, show_points=arg.show_points, show_hints=arg.show_hints, save_answers=arg.save_answers, practice=arg.practice, show_ref=arg.show_ref)
-    print('=' * 79)
-    # print('- Title:      %s' % testconf['title'])   # FIXME problems with UnicodeEncodeError
-    print('- Database:        %s' % testconf['database'])
-    print('- Loaded %i questions from:' % len(testconf['questions']))
-    print('    path:  %s' % testconf['questions_dir'])
-    print('    files: %s' % ', '.join(testconf['files']))
-    print('-' * 79)
-    print('- Starting server...')
-
-    # --- controller
-    root = Root(testconf)
+    # FIXME problems with UnicodeEncodeError
+    logger.error('  Title:      %s' % testconf['title'])
+    logger.error('  Database:        %s' % testconf['database']) # FIXME check if db is ok?
-    # --- Mount and run server
+    # --- site wide configuration (valid for all apps)
     cherrypy.config.update({'tools.staticdir.root': SERVER_PATH})
-    cherrypy.quickstart(root, '/', config=arg.server)
+    cherrypy.config.update(arg.server)
+    # --- app specific configuration
+    app = cherrypy.tree.mount(Root(testconf), '/', arg.server)
+
+    logger.info('Starting server at {}:{}'.format(
+        cherrypy.config['server.socket_host'],
+        cherrypy.config['server.socket_port']))
+
+    if hasattr(cherrypy.engine, "signal_handler"):
+        cherrypy.engine.signal_handler.subscribe()
+    if hasattr(cherrypy.engine, "console_control_handler"):
+        cherrypy.engine.console_control_handler.subscribe()
+
+    cherrypy.engine.start()
+    cherrypy.engine.block()
+
     cherrypy.log('Terminated OK ------------------------', 'APPLICATION')
-    print('\n- Server terminated OK')
-    print('=' * 79)
+    print()
+    logger.critical('-------- !!! Server terminated !!! --------')
@@ -2,21 +2,29 @@
 import os, sys, fnmatch
 import random
 import sqlite3
+import logging
 from datetime import datetime
+
+ch = logging.StreamHandler()
+ch.setLevel(logging.INFO)
+ch.setFormatter(logging.Formatter('%(asctime)s | %(name)-10s | %(levelname)-8s | %(message)s'))
+
+logger = logging.getLogger('test')
+logger.addHandler(ch)
+
 try:
     import yaml
 except ImportError:
-    print('The package "yaml" is missing. See README.md for instructions.')
+    logger.critical('The package "yaml" is missing. See README.md for instructions.')
     sys.exit(1)
 try:
     import json
 except ImportError:
-    print('The package "json" is missing. See README.md for instructions.')
+    logger.critical('The package "json" is missing. See README.md for instructions.')
     sys.exit(1)
-
 # my code
 import questions
 import database
@@ -28,7 +36,7 @@ def read_configuration(filename, debug=False, show_points=False, show_hints=Fals
     try:
         f = open(filename, 'r', encoding='utf-8')
     except IOError:
-        print('[ ERROR ]  Cannot open YAML file "%s"' % filename)
+        logger.critical('Cannot open YAML file "%s"' % filename)
         sys.exit(1)
     else:
         with f:
@@ -36,7 +44,7 @@ def read_configuration(filename, debug=False, show_points=False, show_hints=Fals
                 test = yaml.load(f)
             except yaml.YAMLError as exc:
                 mark = exc.problem_mark
-                print('[ ERROR ]  In YAML file "{0}" near line {1}, column {2}.'.format(filename,mark.line,mark.column+1))
+                logger.critical('In YAML file "{0}" near line {1}, column {2}.'.format(filename,mark.line,mark.column+1))
                 sys.exit(1)
     # -- test yaml was loaded ok
@@ -54,39 +62,39 @@ def read_configuration(filename, debug=False, show_points=False, show_hints=Fals
     # this is the base directory where questions are stored
     test['questions_dir'] = os.path.normpath(os.path.expanduser(str(test.get('questions_dir', os.path.curdir))))
     if not os.path.exists(test['questions_dir']):
-        print('[ ERROR ]  Questions directory "{0}" does not exist.\n           Fix the "questions_dir" key in the configuration file "{1}".'.format(test['questions_dir'], filename))
+        logger.error('Questions directory "{0}" does not exist. Fix the "questions_dir" key in the configuration file "{1}".'.format(test['questions_dir'], filename))
         errors += 1
     # where to put the students answers (optional)
     if 'answers_dir' not in test:
-        print('[ WARNG ]  Missing "answers_dir" in the test configuration file "{0}".\n           Tests are NOT being saved. Grades are still going into the database.'.format(filename))
+        logger.warning('Missing "answers_dir" in "{0}". Tests will NOT be saved.'.format(filename))
         test['save_answers'] = False
     else:
         test['answers_dir'] = os.path.normpath(os.path.expanduser(str(test['answers_dir'])))
         if not os.path.isdir(test['answers_dir']):
-            print('[ ERROR ]  Directory "{0}" does not exist.'.format(test['answers_dir']))
+            logger.error('Directory "{0}" does not exist.'.format(test['answers_dir']))
             errors += 1
         test['save_answers'] = True
     # database with login credentials and grades
     if 'database' not in test:
-        print('[ ERROR ]  Missing "database" key in the test configuration "{0}".'.format(filename))
+        logger.error('Missing "database" key in the test configuration "{0}".'.format(filename))
         errors += 1
     else:
         test['database'] = os.path.normpath(os.path.expanduser(str(test['database'])))
         if not os.path.exists(test['database']):
-            print('[ ERROR ]  Database "{0}" not found.'.format(test['database']))
+            logger.error('Database "{0}" not found.'.format(test['database']))
             errors += 1
     if errors > 0:
-        print('{0} error(s) found. Aborting!'.format(errors))
+        logger.critical('{0} error(s) found. Aborting!'.format(errors))
         sys.exit(1)
     # deal with questions files
     if 'files' not in test:
         # no files were defined = load all from questions_dir
         test['files'] = fnmatch.filter(os.listdir(test['questions_dir']), '*.yaml')
-        print('[ WARNG ]  All YAML files from directory were loaded. Might not be such a good idea...')
+        logger.warning('All YAML files from directory were loaded. Might not be such a good idea...')
     else:
         # only one file
         if isinstance(test['files'], str):
@@ -101,11 +109,14 @@ def read_configuration(filename, debug=False, show_points=False, show_hints=Fals
         # contains only one element
         if isinstance(q, str):
             # normalize question to a dict
-            #       - some_ref
-            # becomes
-            #       - ref: some_ref
-            #         points: 1.0
-            test['questions'][i] = [pool[q]]  # list with just one question
+            #       some_ref   -->    ref: some_ref
+            #                         points: 1.0
+            try:
+                test['questions'][i] = [pool[q]]  # list with just one question
+            except KeyError:
+                logger.critical('Could not find question "{}".'.format(q))
+                sys.exit(1)
+
             test['questions'][i][0]['points'] = 1.0
             # Note: at this moment we do not know the questions types.
             # Some questions, like information, should have default points
@@ -114,8 +125,7 @@ def read_configuration(filename, debug=False, show_points=False, show_hints=Fals
         elif isinstance(q, dict):
             if 'ref' not in q:
-                print('  * Found a question without a "ref" key in the test "{}"'.format(filename))
-                print('    Dictionary contents:', q)
+                logger.critical('Found question missing the "ref" key in "{}"'.format(filename))
                 sys.exit(1)
             if isinstance(q['ref'], str):
@@ -128,7 +138,7 @@ def read_configuration(filename, debug=False, show_points=False, show_hints=Fals
                 try:
                     qq = pool[r]
                 except KeyError:
-                    print('[ WARNG ]  Question reference "{0}" of test "{1}" not found. Skipping...'.format(r, test['ref']))
+                    logger.warning('Question reference "{0}" of test "{1}" not found. Skipping...'.format(r, test['ref']))
                     continue
                 qq['points'] = p
                 l.append(qq)
@@ -148,8 +158,9 @@ class Test(dict):
         for i, qq in enumerate(self['questions']):
             try:
                 q = random.choice(qq)  # select from alternative versions
-            except IndexError:
-                print(qq)  # FIXME
+            except TypeError:
+                logger.error('in question {} (0-based index).'.format(i))
+                continue
             qlist.append(questions.create_question(q))  # create instance
         self['questions'] = qlist
         self['start_time'] = datetime.now()