several fixes

Miguel Barão
1 parent f8d971df
Showing 11 changed files with 232 additions and 176 deletions Show diff stats
BUGS.md
README.md
aprendizations/learnapp.py
aprendizations/main.py
aprendizations/questions.py
aprendizations/serve.py
aprendizations/student.py
aprendizations/tools.py
config/logger-debug.yaml
config/logger.yaml
demo/demo.yaml
 # BUGS
+- duplo clicks no botao "responder" dessincroniza as questões, ver debounce em https://stackoverflow.com/questions/20281546/how-to-prevent-calling-of-en-event-handler-twice-on-fast-clicks
 - quando termina topico devia apagar as perguntas todas (se falhar a gerar novo topico, aparecem perguntas do antigo)
 - apos clicar no botao responder, inactivar o input (importante quando o tempo de correcção é grande)
 - devia mostrar timeout para o aluno saber a razao.
@@ -40,6 +41,7 @@ sqlite3.ProgrammingError: SQLite objects created in a thread can only be used in
 # FIXED
+- forgetting factor is hardcoded in student.py
 - add aprendizatons --version
 - se aluno abre dois tabs no browser, conseque navegar em simultaneo para perguntas diferentes. quando submete uma delas dá asneira. Tem de haver um campo hidden que tenha um céodigo único que indique qual a pergunta. do lado do servidor apnas há o codigo da pergunta corrente, se forem diferentes faz redirect para /.
 - nos topicos learn.yaml, qd falha acrescenta no fim. nao faz sentido.
 # Getting Started
+
+## Installation
+
 To complete the installation we will need to perform the following steps:
 1. install python3.7, pip and npm
 1. download aprendizations from the repository
 1. install javascript libraries (with npm)
 1. install aprendizations (with pip)
-1. initialize database
 1. generate SSL certificates
 1. configure the firewall (optional)
-1. try running `aprendizations demo.yaml`
-These steps are explained next in detail.
+To use the software we need to:
+
+1. initialize database
+1. go to the demo directory (or an existing course)
+1. run `aprendizations demo.yaml`
+
+Each of these steps is explained below.
 ### Install python3.7 with sqlite3 support and npm
@@ -47,16 +54,21 @@ This will install python locally under `~/.local/bin`. Make sure to add it to yo
 ### Install pip
-Python usually includes pip which is accessible through `python -m pip install something`, but it's also convenient to have the `pip` command installed. 
-If the `pip` command is not yet installed, run one of these:
+Python usually includes pip which is accessible through `python -m pip install something`, but it's also convenient to have the `pip` command directly available in the terminal. 
+To install `pip` from the system package manager:
 ```sh
 sudo apt install python3.7-pip     # Ubuntu 19.04+
-python3.7 -m pip install pip       # Ubuntu 18.04
 sudo pkg py37-pip                  # FreeBSD
 sudo port install py37-pip         # MacOS
 ```
+otherwise run:
+
+```sh
+python3.7 -m pip install pip        # install in user area
+```
+
 The latter will install `pip` in your user account under `~/.local/bin`.
 In the end you should be able to run `pip --version` and 
 `python3 -c "import sqlite3"` without errors.
@@ -73,7 +85,7 @@ user = yes
 This will set pip to install modules in the user area (recommended).
-### Install aprendizations and dependencies:
+### Download and install aprendizations:
 ```sh
 git clone https://git.xdi.uevora.pt/mjsb/aprendizations.git
@@ -82,8 +94,7 @@ npm install             # install javascript libraries
 pip install .           # install aprendizations and dependencies
 ```
-Javascript libraries are initially installed in `aprendizations/node_modules` directory.
-These libraries already have symbolic links from `aprendizations/aprendizations/static`.
+Javascript libraries are installed in `aprendizations/node_modules` and are linked from `aprendizations/aprendizations/static`.
 Python packages are usually installed in:
@@ -92,7 +103,7 @@ Python packages are usually installed in:
 When aprendizations is installed with pip, all the dependencies are also installed. The javascript libraries previously installed with npm are copied to the above directory and the cloned repository is no longer needed.
-At this point, aprendizations is installed in
+At this point `aprendizations` is installed in
 ```sh
 ~/.local/bin                          # Linux/FreeBSD
@@ -106,29 +117,6 @@ aprendizations --version
 aprendizations --help
 ```
-## Configuration
-
-### Database
-
-User data is maintained in a sqlite3 database which has to be created manually using the command `initdb-aprendizations`.
-The database file should be located in the same directory as the main 
-YAML configuration file.
-
-For example, to run the included demo do:
-
-```sh
-cd demo                               # contains a small example
-initdb-aprendizations                 # show or initialize database
-initdb-aprendizations --admin         # add admin user
-initdb-aprendizations inscricoes.csv  # add students from CSV
-initdb-aprendizations --add 1184 "Aladino da Silva"   # add new user
-initdb-aprendizations --update 1184 --pw alibaba      # update password
-initdb-aprendizations --help          # for available options
-```
-
-The default password is equal to the user name, if left undefined.
-
-
 ### SSL Certificates
 We need certificates for https. Certificates can be self-signed or validated by a trusted authority.
@@ -150,7 +138,7 @@ Install the certbot from LetsEncrypt:
 ```sh
 sudo pkg install py36-certbot       # FreeBSD
-sudo apt install certbot            # Linux Ubuntu
+sudo apt install certbot            # Ubuntu
 ```
 To generate or renew the certificates, ports 80 and 443 have to be accessible. The firewall and webserver have to be stopped. 
@@ -168,6 +156,30 @@ sudo cp /usr/local/etc/letsencrypt/live/www.example.com/privkey.pem .
 chmod 400 cert.pem privkey.pem
 ```
+
+## Configuration
+
+### Database
+
+User data is maintained in a sqlite3 database which has to be created manually using the `initdb-aprendizations` command.
+The database file should be located in the same directory as the main 
+YAML configuration file.
+
+For example, to run the included demo do:
+
+```sh
+cd demo                               # contains a small example
+initdb-aprendizations                 # show or initialize database
+initdb-aprendizations --admin         # add admin user
+initdb-aprendizations inscricoes.csv  # add students from CSV
+initdb-aprendizations --add 1184 "Aladino da Silva"   # add new user
+initdb-aprendizations --update 1184 --pw alibaba      # update password
+initdb-aprendizations --help          # for available options
+```
+
+The default password is equal to the user name, if left undefined.
+
+
 ### Running the demo
 The application includes a small example in `demo/demo.yaml` that can be used for initial testing. Run it with
@@ -178,7 +190,7 @@ aprendizations demo.yaml
 ```
 Open the browser at [https://127.0.0.1:8443](https://127.0.0.1:8443). 
-If it everything looks good, check at the correct address 
+If everything looks good, check at the correct address 
 `https://www.example.com:8443`.
 The option `--debug` provides more verbose logging and might 
 be useful during testing.
@@ -198,7 +210,7 @@ rdr on $ext_if proto tcp from any to any port 80 -&gt; 127.0.0.1 port 8080
 rdr on $ext_if proto tcp from any to any port 443 -> 127.0.0.1 port 8443
 ```
-Under virtualbox with guest additions use `ext_if="vtnet0"`.
+Virtualbox with guest additions uses `ext_if="vtnet0"`.
 Edit `/etc/rc.conf`
@@ -228,6 +240,17 @@ Make sure the following steps have been done:
 - (optional) configure the firewall to do port forwarding
 - run `aprendizations demo.yaml --check`
+## Keeping aprendizations updated
+
+To update aprendizations to the latest version do:
+
+```sh
+cd aprendizations
+git pull                # get latest version
+npm update              # update javascript libraries
+pip install -U .        # updates installed version to latest
+```
+
 ## Troubleshooting
 To help with troubleshooting, use the option `--debug` when running the server. 
@@ -79,7 +79,7 @@ class LearnApp(object):
         errors = 0
         for qref in self.factory:
-            logger.debug(f'[sanity_check_questions] Checking "{qref}"...')
+            logger.debug(f'checking {qref}...')
             try:
                 q = self.factory[qref].generate()
             except Exception:
@@ -195,9 +195,9 @@ class LearnApp(object):
     # ------------------------------------------------------------------------
     async def check_answer(self, uid, answer):
         knowledge = self.online[uid]['state']
+        topic = knowledge.get_current_topic()
         q, action = await knowledge.check_answer(answer)  # may move questions
         logger.info(f'User "{uid}" got {q["grade"]:.2} in "{q["ref"]}"')
-        topic = knowledge.get_current_topic()
         # always save grade of answered question
         with self.db_session() as s:
@@ -208,7 +208,7 @@ class LearnApp(object):
                 finishtime=str(q['finish_time']),
                 student_id=uid,
                 topic_id=topic))
-            logger.debug(f'[check_answer] Saved "{q["ref"]}" into database')
+            logger.debug(f'db insert answer of {q["ref"]}')
         if knowledge.topic_has_finished():
             # finished topic, save into database
@@ -222,7 +222,7 @@ class LearnApp(object):
                     .one_or_none()
                 if a is None:
                     # insert new studenttopic into database
-                    logger.debug('[check_answer] Database insert studenttopic')
+                    logger.debug('db insert studenttopic')
                     t = s.query(Topic).get(topic)
                     u = s.query(Student).get(uid)
                     # association object
@@ -231,14 +231,12 @@ class LearnApp(object):
                     u.topics.append(a)
                 else:
                     # update studenttopic in database
-                    logger.debug('[check_answer] Database update studenttopic')
+                    logger.debug(f'db update studenttopic to level {level}')
                     a.level = level
                     a.date = date
                 s.add(a)
-            logger.debug(f'[check_answer] Saved topic "{topic}" into database')
-
         return q, action
     # ------------------------------------------------------------------------
@@ -347,7 +345,7 @@ class LearnApp(object):
     # Buils dictionary of question factories
     # ------------------------------------------------------------------------
     def make_factory(self) -> Dict[str, QFactory]:
-        logger.info('Building questions factory...')
+        logger.info('Building questions factory:')
         factory = {}    # {'qref': QFactory()}
         g = self.deps
         for tref in g.nodes():
@@ -4,34 +4,17 @@
 import argparse
 import logging
 from os import environ, path
-import signal
 import ssl
 import sys
-# third party libraries
-import tornado
-
 # this project
 from .learnapp import LearnApp, DatabaseUnusableError
-from .serve import WebApplication
+from .serve import run_webserver
 from .tools import load_yaml
 from . import APP_NAME, APP_VERSION
 # ----------------------------------------------------------------------------
-# Signal handler to catch Ctrl-C and abort server
-# ----------------------------------------------------------------------------
-def signal_handler(signal, frame):
-    r = input(' --> Stop webserver? (yes/no) ').lower()
-    if r == 'yes':
-        tornado.ioloop.IOLoop.current().stop()
-        logging.critical('Webserver stopped.')
-        sys.exit(0)
-    else:
-        logging.info('Abort canceled...')
-
-
-# ----------------------------------------------------------------------------
 def parse_cmdline_arguments():
     argparser = argparse.ArgumentParser(
         description='Server for online learning. Students and topics '
@@ -91,7 +74,7 @@ def get_logger_config(debug=False):
         'version': 1,
         'formatters': {
             'standard': {
-                'format': '%(asctime)s | %(levelname)-10s | %(message)s',
+                'format': '%(asctime)s | %(levelname)-8s | %(message)s',
                 'datefmt': '%Y-%m-%d %H:%M:%S',
                 },
             },
@@ -115,14 +98,14 @@ def get_logger_config(debug=False):
             'handlers': ['default'],
             'level': level,
             'propagate': False,
-            } for module in ['learnapp', 'models', 'factory', 'questions',
-                             'knowledge', 'tools']})
+            } for module in ['learnapp', 'models', 'factory', 'tools', 'serve',
+                             'questions', 'student']})
     return load_yaml(config_file, default=default_config)
 # ----------------------------------------------------------------------------
-# Tornado web server
+# Start application and webserver
 # ----------------------------------------------------------------------------
 def main():
     # --- Commandline argument parsing
@@ -144,34 +127,6 @@ def main():
     logging.info('====================== Start Logging ======================')
-    # --- start application
-    logging.info('Starting App...')
-    try:
-        learnapp = LearnApp(arg.conffile, prefix=arg.prefix, db=arg.db,
-                            check=arg.check)
-    except DatabaseUnusableError:
-        logging.critical('Failed to start application.')
-        print('--------------------------------------------------------------')
-        print('Could not find a usable database. Use one of the follwing     ')
-        print('commands to initialize:                                       ')
-        print('                                                              ')
-        print('  initdb-aprendizations --admin            # add admin        ')
-        print('  initdb-aprendizations -a 86 "Max Smart"  # add student      ')
-        print('  initdb-aprendizations students.csv       # add many students')
-        print('--------------------------------------------------------------')
-        sys.exit(1)
-    except Exception:
-        logging.critical('Failed to start application.')
-        sys.exit(1)
-
-    # --- create web application
-    logging.info('Starting Web App (tornado)...')
-    try:
-        webapp = WebApplication(learnapp, debug=arg.debug)
-    except Exception:
-        logging.critical('Failed to start web application.')
-        sys.exit(1)
-
     # --- get SSL certificates
     if 'XDG_DATA_HOME' in environ:
         certs_dir = path.join(environ['XDG_DATA_HOME'], 'certs')
@@ -186,44 +141,46 @@ def main():
         logging.critical(f'SSL certificates missing in {certs_dir}')
         print('--------------------------------------------------------------')
         print('Certificates should be issued by a certificate authority (CA),')
-        print('such as https://letsencrypt.org, and then copied to:          ')
-        print('                                                              ')
-        print(f'  {certs_dir:<62}')
-        print('                                                              ')
+        print('such as https://letsencrypt.org.                              ')
         print('For testing purposes a selfsigned certificate can be generated')
         print('locally by running:                                           ')
         print('                                                              ')
         print('  openssl req -x509 -newkey rsa:4096 -keyout privkey.pem \\   ')
         print('          -out cert.pem -days 365 -nodes                      ')
         print('                                                              ')
+        print('Copy the cert.pem and privkey.pem files to:                   ')
+        print('                                                              ')
+        print(f'  {certs_dir:<62}')
+        print('                                                              ')
+        print('(See README.md for more information)                          ')
         print('--------------------------------------------------------------')
         sys.exit(1)
+    else:
+        logging.info('SSL certificates loaded')
-    # --- create webserver
+    # --- start application
     try:
-        httpserver = tornado.httpserver.HTTPServer(webapp, ssl_options=ssl_ctx)
-    except ValueError:
-        logging.critical('Certificates cert.pem and privkey.pem not found')
+        learnapp = LearnApp(arg.conffile, prefix=arg.prefix, db=arg.db,
+                            check=arg.check)
+    except DatabaseUnusableError:
+        logging.critical('Failed to start application.')
+        print('--------------------------------------------------------------')
+        print('Could not find a usable database. Use one of the follwing     ')
+        print('commands to initialize:                                       ')
+        print('                                                              ')
+        print('  initdb-aprendizations --admin            # add admin        ')
+        print('  initdb-aprendizations -a 86 "Max Smart"  # add student      ')
+        print('  initdb-aprendizations students.csv       # add many students')
+        print('--------------------------------------------------------------')
         sys.exit(1)
-
-    try:
-        httpserver.listen(arg.port)
-    except OSError:
-        logging.critical(f'Cannot bind port {arg.port}. Already in use?')
+    except Exception:
+        logging.critical('Failed to start application.')
         sys.exit(1)
+    else:
+        logging.info('Backend application started')
-    logging.info(f'Listening on port {arg.port}.')
-
-    # --- run webserver
-    signal.signal(signal.SIGINT, signal_handler)
-    logging.info('Webserver running.  (Ctrl-C to stop)')
-
-    try:
-        tornado.ioloop.IOLoop.current().start()  # running...
-    except Exception:
-        logging.critical('Webserver stopped.')
-        tornado.ioloop.IOLoop.current().stop()
-        raise
+    # --- run webserver forever
+    run_webserver(app=learnapp, ssl=ssl_ctx, port=arg.port, debug=arg.debug)
 # ----------------------------------------------------------------------------
@@ -461,7 +461,7 @@ class QFactory(object):
     # i.e. a question object (radio, checkbox, ...).
     # -----------------------------------------------------------------------
     def generate(self) -> Question:
-        logger.debug(f'[QFactory.generate] "{self.question["ref"]}"...')
+        logger.debug(f'generating {self.question["ref"]}...')
         # Shallow copy so that script generated questions will not replace
         # the original generators
         q = self.question.copy()
@@ -492,7 +492,7 @@ class QFactory(object):
     # -----------------------------------------------------------------------
     async def generate_async(self) -> Question:
-        logger.debug(f'[QFactory.generate_async] "{self.question["ref"]}"...')
+        logger.debug(f'generating {self.question["ref"]}...')
         # Shallow copy so that script generated questions will not replace
         # the original generators
         q = self.question.copy()
@@ -520,5 +520,5 @@ class QFactory(object):
             logger.error(f'Invalid type "{q["type"]}" in "{q["ref"]}"')
             raise
         else:
-            logger.debug(f'[generate_async] Done instance of {q["ref"]}')
+            logger.debug('ok')
             return qinstance
@@ -6,6 +6,8 @@ import functools
 import logging.config
 import mimetypes
 from os import path
+import signal
+import sys
 import uuid
 # third party libraries
@@ -16,6 +18,9 @@ from tornado.escape import to_unicode
 from .tools import md_to_html
 from . import APP_NAME
+# setup logger for this module
+logger = logging.getLogger(__name__)
+
 # ----------------------------------------------------------------------------
 # Decorator used to restrict access to the administrator only
@@ -211,11 +216,11 @@ class FileHandler(BaseHandler):
             with open(filepath, 'rb') as f:
                 data = f.read()
         except FileNotFoundError:
-            logging.error(f'File not found: {filepath}')
+            logger.error(f'File not found: {filepath}')
         except PermissionError:
-            logging.error(f'No permission: {filepath}')
+            logger.error(f'No permission: {filepath}')
         except Exception:
-            logging.error(f'Error reading: {filepath}')
+            logger.error(f'Error reading: {filepath}')
             raise
         else:
             self.set_header("Content-Type", content_type)
@@ -244,7 +249,7 @@ class QuestionHandler(BaseHandler):
     # --- get question to render
     @tornado.web.authenticated
     def get(self):
-        logging.debug('[QuestionHandler.get]')
+        logger.debug('[QuestionHandler.get]')
         user = self.current_user
         q = self.learn.get_current_question(user)
@@ -275,7 +280,7 @@ class QuestionHandler(BaseHandler):
     # --- post answer, returns what to do next: shake, new_question, finished
     @tornado.web.authenticated
     async def post(self) -> None:
-        logging.debug('[QuestionHandler.post]')
+        logger.debug('[QuestionHandler.post]')
         user = self.current_user
         answer = self.get_body_arguments('answer')  # list
@@ -283,7 +288,7 @@ class QuestionHandler(BaseHandler):
         answer_qid = self.get_body_arguments('qid')[0]
         current_qid = self.learn.get_current_question_id(user)
         if answer_qid != current_qid:
-            logging.info(f'User {user} desynchronized questions')
+            logger.info(f'User {user} desynchronized questions')
             self.write({
                 'method': 'invalid',
                 'params': {
@@ -299,14 +304,14 @@ class QuestionHandler(BaseHandler):
         # --- answers are in a list. fix depending on question type
         qtype = self.learn.get_student_question_type(user)
         if qtype in ('success', 'information', 'info'):
-            answer = None
+            ans = None
         elif qtype == 'radio' and not answer:
-            answer = None
+            ans = None
         elif qtype != 'checkbox':   # radio, text, textarea, ...
-            answer = answer[0]
+            ans = answer[0]
         # --- check answer (nonblocking) and get corrected question and action
-        q, action = await self.learn.check_answer(user, answer)
+        q, action = await self.learn.check_answer(user, ans)
         # --- built response to return
         response = {'method': action, 'params': {}}
@@ -349,6 +354,59 @@ class QuestionHandler(BaseHandler):
                 'tries': q['tries'],
                 }
         else:
-            logging.error(f'Unknown action: {action}')
+            logger.error(f'Unknown action: {action}')
         self.write(response)
+
+
+# ----------------------------------------------------------------------------
+# Signal handler to catch Ctrl-C and abort server
+# ----------------------------------------------------------------------------
+def signal_handler(signal, frame):
+    r = input(' --> Stop webserver? (yes/no) ').lower()
+    if r == 'yes':
+        tornado.ioloop.IOLoop.current().stop()
+        logger.critical('Webserver stopped.')
+        sys.exit(0)
+    else:
+        logger.info('Abort canceled...')
+
+
+# ----------------------------------------------------------------------------
+def run_webserver(app, ssl, port=8443, debug=False):
+    # --- create web application
+    try:
+        webapp = WebApplication(app, debug=debug)
+    except Exception:
+        logger.critical('Failed to start web application.')
+        sys.exit(1)
+    else:
+        logger.info('Web application started (tornado.web.Application)')
+
+    # --- create tornado webserver
+    try:
+        httpserver = tornado.httpserver.HTTPServer(webapp, ssl_options=ssl)
+    except ValueError:
+        logger.critical('Certificates cert.pem and privkey.pem not found')
+        sys.exit(1)
+    else:
+        logger.debug('HTTP server started')
+
+    try:
+        httpserver.listen(port)
+    except OSError:
+        logger.critical(f'Cannot bind port {port}. Already in use?')
+        sys.exit(1)
+    else:
+        logger.info(f'HTTP server listening on port {port}')
+
+    # --- run webserver
+    signal.signal(signal.SIGINT, signal_handler)
+    logger.info('Webserver running.  (Ctrl-C to stop)')
+
+    try:
+        tornado.ioloop.IOLoop.current().start()  # running...
+    except Exception:
+        logger.critical('Webserver stopped.')
+        tornado.ioloop.IOLoop.current().stop()
+        raise
@@ -3,20 +3,26 @@
 import random
 from datetime import datetime
 import logging
+from typing import List, Optional
 # third party libraries
 import networkx as nx
+# this project
+from .questions import Question
+
+
 # setup logger for this module
 logger = logging.getLogger(__name__)
 # ----------------------------------------------------------------------------
-# kowledge state of each student....??
+# kowledge state of a student
 # Contains:
-#   state - dict of topics with state of unlocked topics
+#   state - dict of unlocked topics and their levels
 #   deps  - access to dependency graph shared between students
-#   topic_sequence - list with the order of recommended topics
+#   topic_sequence - list with the recommended topic sequence
+#   current_topic - nameref of the current topic
 # ----------------------------------------------------------------------------
 class StudentState(object):
     # =======================================================================
@@ -34,13 +40,13 @@ class StudentState(object):
     # ------------------------------------------------------------------------
     # Updates the proficiency levels of the topics, with forgetting factor
-    # FIXME no dependencies are considered yet...
     # ------------------------------------------------------------------------
     def update_topic_levels(self):
         now = datetime.now()
         for tref, s in self.state.items():
             dt = now - s['date']
-            s['level'] *= 0.98 ** dt.days   # forgetting factor
+            forgetting_factor = self.deps.node[tref]['forgetting_factor']
+            s['level'] *= forgetting_factor ** dt.days   # forgetting factor
     # ------------------------------------------------------------------------
     # Unlock topics whose dependencies are satisfied (> min_level)
@@ -51,13 +57,13 @@ class StudentState(object):
                 pred = self.deps.predecessors(topic)
                 min_level = self.deps.node[topic]['min_level']
                 if all(d in self.state and self.state[d]['level'] > min_level
-                   for d in pred):  # all deps are greater than min_level
+                       for d in pred):  # all deps are greater than min_level
                     self.state[topic] = {
                         'level': 0.0,           # unlocked
                         'date': datetime.now()
                         }
-                    logger.debug(f'[unlock_topics] Unlocked "{topic}".')
+                    logger.debug(f'unlocked "{topic}"')
                 # else:  # lock this topic if deps do not satisfy min_level
                 #     del self.state[topic]
@@ -66,16 +72,17 @@ class StudentState(object):
     #    questions: list of generated questions to do in the topic
     #    current_question: the current question to be presented
     # ------------------------------------------------------------------------
-    async def start_topic(self, topic):
-        logger.debug(f'[start_topic] topic "{topic}"')
+    async def start_topic(self, topic: str):
+        logger.debug(f'starting "{topic}"')
+        # avoid regenerating questions in the middle of the current topic
         if self.current_topic == topic:
             logger.info('Restarting current topic is not allowed.')
             return
         # do not allow locked topics
         if self.is_locked(topic):
-            logger.debug(f'[start_topic] topic "{topic}" is locked')
+            logger.debug(f'is locked "{topic}"')
             return
         # starting new topic
@@ -89,18 +96,13 @@ class StudentState(object):
             questions = random.sample(t['questions'], k=k)
         else:
             questions = t['questions'][:k]
-        logger.debug(f'[start_topic] questions: {", ".join(questions)}')
+        logger.debug(f'selected questions:  {", ".join(questions)}')
-        # synchronous
-        # self.questions = [self.factory[ref].generate()
-        #                   for ref in questions]
-
-        # asynchronous:
         self.questions = [await self.factory[ref].generate_async()
                           for ref in questions]
         n = len(self.questions)
-        logger.debug(f'[start_topic] generated {n} questions')
+        logger.debug(f'generated {n} questions')
         # get first question
         self.next_question()
@@ -111,14 +113,14 @@ class StudentState(object):
     # The current topic is unchanged.
     # ------------------------------------------------------------------------
     def finish_topic(self):
-        logger.debug(f'[finish_topic] current_topic {self.current_topic}')
+        logger.debug(f'finished {self.current_topic}')
         self.state[self.current_topic] = {
             'date': datetime.now(),
             'level': self.correct_answers / (self.correct_answers +
                                              self.wrong_answers)
             }
-        # self.current_topic = None
+        self.current_topic = None
         self.unlock_topics()
     # ------------------------------------------------------------------------
@@ -128,13 +130,12 @@ class StudentState(object):
     #   - if wrong, counts number of tries. If exceeded, moves on.
     # ------------------------------------------------------------------------
     async def check_answer(self, answer):
-        logger.debug('[check_answer]')
-
         q = self.current_question
         q['answer'] = answer
         q['finish_time'] = datetime.now()
+        logger.debug(f'checking answer of {q["ref"]}...')
         await q.correct_async()
-        logger.debug(f'[check_answer] Grade {q["grade"]:.2} in {q["ref"]}')
+        logger.debug(f'grade = {q["grade"]:.2}')
         if q['grade'] > 0.999:
             self.correct_answers += 1
@@ -150,7 +151,7 @@ class StudentState(object):
             else:
                 action = 'wrong'
                 if self.current_question['append_wrong']:
-                    logger.debug('[check_answer] Wrong, append new instance')
+                    logger.debug('wrong answer, append new question')
                     self.questions.append(self.factory[q['ref']].generate())
                 self.next_question()
@@ -158,9 +159,9 @@ class StudentState(object):
         return q, action
     # ------------------------------------------------------------------------
-    # Move to next question
+    # Move to next question, or None
     # ------------------------------------------------------------------------
-    def next_question(self):
+    def next_question(self) -> Optional[Question]:
         try:
             self.current_question = self.questions.pop(0)
         except IndexError:
@@ -171,7 +172,7 @@ class StudentState(object):
             default_maxtries = self.deps.nodes[self.current_topic]['max_tries']
             maxtries = self.current_question.get('max_tries', default_maxtries)
             self.current_question['tries'] = maxtries
-            logger.debug(f'[next_question] "{self.current_question["ref"]}"')
+            logger.debug(f'current_question = {self.current_question["ref"]}')
         return self.current_question  # question or None
@@ -179,28 +180,35 @@ class StudentState(object):
     # pure functions of the state (no side effects)
     # ========================================================================
-    def topic_has_finished(self):
-        return self.current_question is None
+    def topic_has_finished(self) -> bool:
+        return self.current_topic is None
     # ------------------------------------------------------------------------
     # compute recommended sequence of topics  ['a', 'b', ...]
     # ------------------------------------------------------------------------
-    def recommend_topic_sequence(self, target=None):
+    def recommend_topic_sequence(self, target: str = '') -> List[str]:
         tt = list(nx.topological_sort(self.deps))
+        try:
+            idx = tt.index(target)
+        except ValueError:
+            pass
+        else:
+            del tt[idx:]
+
         unlocked = [t for t in tt if t in self.state]
         locked = [t for t in tt if t not in unlocked]
         return unlocked + locked
     # ------------------------------------------------------------------------
-    def get_current_question(self):
+    def get_current_question(self) -> Optional[Question]:
         return self.current_question
     # ------------------------------------------------------------------------
-    def get_current_topic(self):
+    def get_current_topic(self) -> Optional[str]:
         return self.current_topic
     # ------------------------------------------------------------------------
-    def is_locked(self, topic):
+    def is_locked(self, topic: str) -> bool:
         return topic not in self.state
     # ------------------------------------------------------------------------
@@ -217,16 +225,16 @@ class StudentState(object):
             } for ref in self.topic_sequence]
     # ------------------------------------------------------------------------
-    def get_topic_progress(self):
+    def get_topic_progress(self) -> float:
         return self.correct_answers / (1 + self.correct_answers +
                                        len(self.questions))
     # ------------------------------------------------------------------------
-    def get_topic_level(self, topic):
+    def get_topic_level(self, topic: str) -> float:
         return self.state[topic]['level']
     # ------------------------------------------------------------------------
-    def get_topic_date(self, topic):
+    def get_topic_date(self, topic: str):
         return self.state[topic]['date']
     # ------------------------------------------------------------------------
@@ -154,7 +154,7 @@ def load_yaml(filename: str, default: Any = None) -&gt; Any:
             except yaml.YAMLError as e:
                 if hasattr(e, 'problem_mark'):
                     mark = e.problem_mark
-                    logger.error(f'File "{filename}" near line {mark.line}, '
+                    logger.error(f'File "{filename}" near line {mark.line+1}, '
                                  f'column {mark.column+1}')
                 else:
                     logger.error(f'File "{filename}"')
@@ -5,8 +5,8 @@ formatters:
     void:
         format: ''
     standard:
-        format: '%(asctime)s | %(levelname)-9s | %(name)-24s | %(thread)-15d | %(message)s'
-        datefmt: '%H:%M:%S'
+        format: '%(asctime)s | %(thread)-15d | %(levelname)-8s | %(module)-10s | %(funcName)-20s | %(message)s'
+        # datefmt: '%H:%M:%S'
 handlers:
     default:
@@ -25,7 +25,7 @@ loggers:
         level: 'DEBUG'
         propagate: false
-    'aprendizations.knowledge':
+    'aprendizations.student':
         handlers: ['default']
         level: 'DEBUG'
         propagate: false
@@ -44,3 +44,8 @@ loggers:
         handlers: ['default']
         level: 'DEBUG'
         propagate: false
+
+    'aprendizations.serve':
+        handlers: ['default']
+        level: 'DEBUG'
+        propagate: false
@@ -5,7 +5,7 @@ formatters:
     void:
         format: ''
     standard:
-        format: '%(asctime)s | %(thread)-15d | %(levelname)-9s | %(message)s'
+        format: '%(asctime)s | %(levelname)-8s | %(module)-10s | %(message)s'
         datefmt: '%Y-%m-%d %H:%M:%S'
 handlers:
@@ -25,7 +25,7 @@ loggers:
         level: 'INFO'
         propagate: false
-    'aprendizations.knowledge':
+    'aprendizations.student':
         handlers: ['default']
         level: 'INFO'
         propagate: false
@@ -44,3 +44,8 @@ loggers:
         handlers: ['default']
         level: 'INFO'
         propagate: false
+
+    'aprendizations.serve':
+        handlers: ['default']
+        level: 'INFO'
+        propagate: false
@@ -3,8 +3,7 @@
 title: Example
 database: students.db
-
-# values applie to each topic, if undefined there
+# values applied to each topic, if undefined there
 file: questions.yaml
 shuffle_questions: true
 choose: 6
@@ -27,3 +26,4 @@ topics:
     name: Sistema solar
     deps:
       - math
+    forgetting_factor: 0.1
	@@ -461,7 +461,7 @@ class QFactory(object):		@@ -461,7 +461,7 @@ class QFactory(object):
461	# i.e. a question object (radio, checkbox, ...).	461	# i.e. a question object (radio, checkbox, ...).
462	# -----------------------------------------------------------------------	462	# -----------------------------------------------------------------------
463	def generate(self) -> Question:	463	def generate(self) -> Question:
464	- logger.debug(f'[QFactory.generate] "{self.question["ref"]}"...')	464	+ logger.debug(f'generating {self.question["ref"]}...')
465	# Shallow copy so that script generated questions will not replace	465	# Shallow copy so that script generated questions will not replace
466	# the original generators	466	# the original generators
467	q = self.question.copy()	467	q = self.question.copy()
	@@ -492,7 +492,7 @@ class QFactory(object):		@@ -492,7 +492,7 @@ class QFactory(object):
492		492
493	# -----------------------------------------------------------------------	493	# -----------------------------------------------------------------------
494	async def generate_async(self) -> Question:	494	async def generate_async(self) -> Question:
495	- logger.debug(f'[QFactory.generate_async] "{self.question["ref"]}"...')	495	+ logger.debug(f'generating {self.question["ref"]}...')
496	# Shallow copy so that script generated questions will not replace	496	# Shallow copy so that script generated questions will not replace
497	# the original generators	497	# the original generators
498	q = self.question.copy()	498	q = self.question.copy()
	@@ -520,5 +520,5 @@ class QFactory(object):		@@ -520,5 +520,5 @@ class QFactory(object):
520	logger.error(f'Invalid type "{q["type"]}" in "{q["ref"]}"')	520	logger.error(f'Invalid type "{q["type"]}" in "{q["ref"]}"')
521	raise	521	raise
522	else:	522	else:
523	- logger.debug(f'[generate_async] Done instance of {q["ref"]}')	523	+ logger.debug('ok')
524	return qinstance	524	return qinstance
	@@ -6,6 +6,8 @@ import functools		@@ -6,6 +6,8 @@ import functools
6	import logging.config	6	import logging.config
7	import mimetypes	7	import mimetypes
8	from os import path	8	from os import path
		9	+import signal
		10	+import sys
9	import uuid	11	import uuid
10		12
11	# third party libraries	13	# third party libraries
	@@ -16,6 +18,9 @@ from tornado.escape import to_unicode		@@ -16,6 +18,9 @@ from tornado.escape import to_unicode
16	from .tools import md_to_html	18	from .tools import md_to_html
17	from . import APP_NAME	19	from . import APP_NAME
18		20
		21	+# setup logger for this module
		22	+logger = logging.getLogger(__name__)
		23	+
19		24
20	# ----------------------------------------------------------------------------	25	# ----------------------------------------------------------------------------
21	# Decorator used to restrict access to the administrator only	26	# Decorator used to restrict access to the administrator only
	@@ -211,11 +216,11 @@ class FileHandler(BaseHandler):		@@ -211,11 +216,11 @@ class FileHandler(BaseHandler):
211	with open(filepath, 'rb') as f:	216	with open(filepath, 'rb') as f:
212	data = f.read()	217	data = f.read()
213	except FileNotFoundError:	218	except FileNotFoundError:
214	- logging.error(f'File not found: {filepath}')	219	+ logger.error(f'File not found: {filepath}')
215	except PermissionError:	220	except PermissionError:
216	- logging.error(f'No permission: {filepath}')	221	+ logger.error(f'No permission: {filepath}')
217	except Exception:	222	except Exception:
218	- logging.error(f'Error reading: {filepath}')	223	+ logger.error(f'Error reading: {filepath}')
219	raise	224	raise
220	else:	225	else:
221	self.set_header("Content-Type", content_type)	226	self.set_header("Content-Type", content_type)
	@@ -244,7 +249,7 @@ class QuestionHandler(BaseHandler):		@@ -244,7 +249,7 @@ class QuestionHandler(BaseHandler):
244	# --- get question to render	249	# --- get question to render
245	@tornado.web.authenticated	250	@tornado.web.authenticated
246	def get(self):	251	def get(self):
247	- logging.debug('[QuestionHandler.get]')	252	+ logger.debug('[QuestionHandler.get]')
248	user = self.current_user	253	user = self.current_user
249	q = self.learn.get_current_question(user)	254	q = self.learn.get_current_question(user)
250		255
	@@ -275,7 +280,7 @@ class QuestionHandler(BaseHandler):		@@ -275,7 +280,7 @@ class QuestionHandler(BaseHandler):
275	# --- post answer, returns what to do next: shake, new_question, finished	280	# --- post answer, returns what to do next: shake, new_question, finished
276	@tornado.web.authenticated	281	@tornado.web.authenticated
277	async def post(self) -> None:	282	async def post(self) -> None:
278	- logging.debug('[QuestionHandler.post]')	283	+ logger.debug('[QuestionHandler.post]')
279	user = self.current_user	284	user = self.current_user
280	answer = self.get_body_arguments('answer') # list	285	answer = self.get_body_arguments('answer') # list
281		286
	@@ -283,7 +288,7 @@ class QuestionHandler(BaseHandler):		@@ -283,7 +288,7 @@ class QuestionHandler(BaseHandler):
283	answer_qid = self.get_body_arguments('qid')[0]	288	answer_qid = self.get_body_arguments('qid')[0]
284	current_qid = self.learn.get_current_question_id(user)	289	current_qid = self.learn.get_current_question_id(user)
285	if answer_qid != current_qid:	290	if answer_qid != current_qid:
286	- logging.info(f'User {user} desynchronized questions')	291	+ logger.info(f'User {user} desynchronized questions')
287	self.write({	292	self.write({
288	'method': 'invalid',	293	'method': 'invalid',
289	'params': {	294	'params': {
	@@ -299,14 +304,14 @@ class QuestionHandler(BaseHandler):		@@ -299,14 +304,14 @@ class QuestionHandler(BaseHandler):
299	# --- answers are in a list. fix depending on question type	304	# --- answers are in a list. fix depending on question type
300	qtype = self.learn.get_student_question_type(user)	305	qtype = self.learn.get_student_question_type(user)
301	if qtype in ('success', 'information', 'info'):	306	if qtype in ('success', 'information', 'info'):
302	- answer = None	307	+ ans = None
303	elif qtype == 'radio' and not answer:	308	elif qtype == 'radio' and not answer:
304	- answer = None	309	+ ans = None
305	elif qtype != 'checkbox': # radio, text, textarea, ...	310	elif qtype != 'checkbox': # radio, text, textarea, ...
306	- answer = answer[0]	311	+ ans = answer[0]
307		312
308	# --- check answer (nonblocking) and get corrected question and action	313	# --- check answer (nonblocking) and get corrected question and action
309	- q, action = await self.learn.check_answer(user, answer)	314	+ q, action = await self.learn.check_answer(user, ans)
310		315
311	# --- built response to return	316	# --- built response to return
312	response = {'method': action, 'params': {}}	317	response = {'method': action, 'params': {}}
	@@ -349,6 +354,59 @@ class QuestionHandler(BaseHandler):		@@ -349,6 +354,59 @@ class QuestionHandler(BaseHandler):
349	'tries': q['tries'],	354	'tries': q['tries'],
350	}	355	}
351	else:	356	else:
352	- logging.error(f'Unknown action: {action}')	357	+ logger.error(f'Unknown action: {action}')
353		358
354	self.write(response)	359	self.write(response)
		360	+
		361	+
		362	+# ----------------------------------------------------------------------------
		363	+# Signal handler to catch Ctrl-C and abort server
		364	+# ----------------------------------------------------------------------------
		365	+def signal_handler(signal, frame):
		366	+ r = input(' --> Stop webserver? (yes/no) ').lower()
		367	+ if r == 'yes':
		368	+ tornado.ioloop.IOLoop.current().stop()
		369	+ logger.critical('Webserver stopped.')
		370	+ sys.exit(0)
		371	+ else:
		372	+ logger.info('Abort canceled...')
		373	+
		374	+
		375	+# ----------------------------------------------------------------------------
		376	+def run_webserver(app, ssl, port=8443, debug=False):
		377	+ # --- create web application
		378	+ try:
		379	+ webapp = WebApplication(app, debug=debug)
		380	+ except Exception:
		381	+ logger.critical('Failed to start web application.')
		382	+ sys.exit(1)
		383	+ else:
		384	+ logger.info('Web application started (tornado.web.Application)')
		385	+
		386	+ # --- create tornado webserver
		387	+ try:
		388	+ httpserver = tornado.httpserver.HTTPServer(webapp, ssl_options=ssl)
		389	+ except ValueError:
		390	+ logger.critical('Certificates cert.pem and privkey.pem not found')
		391	+ sys.exit(1)
		392	+ else:
		393	+ logger.debug('HTTP server started')
		394	+
		395	+ try:
		396	+ httpserver.listen(port)
		397	+ except OSError:
		398	+ logger.critical(f'Cannot bind port {port}. Already in use?')
		399	+ sys.exit(1)
		400	+ else:
		401	+ logger.info(f'HTTP server listening on port {port}')
		402	+
		403	+ # --- run webserver
		404	+ signal.signal(signal.SIGINT, signal_handler)
		405	+ logger.info('Webserver running. (Ctrl-C to stop)')
		406	+
		407	+ try:
		408	+ tornado.ioloop.IOLoop.current().start() # running...
		409	+ except Exception:
		410	+ logger.critical('Webserver stopped.')
		411	+ tornado.ioloop.IOLoop.current().stop()
		412	+ raise
	@@ -154,7 +154,7 @@ def load_yaml(filename: str, default: Any = None) -> Any:		@@ -154,7 +154,7 @@ def load_yaml(filename: str, default: Any = None) -> Any:
154	except yaml.YAMLError as e:	154	except yaml.YAMLError as e:
155	if hasattr(e, 'problem_mark'):	155	if hasattr(e, 'problem_mark'):
156	mark = e.problem_mark	156	mark = e.problem_mark
157	- logger.error(f'File "{filename}" near line {mark.line}, '	157	+ logger.error(f'File "{filename}" near line {mark.line+1}, '
158	f'column {mark.column+1}')	158	f'column {mark.column+1}')
159	else:	159	else:
160	logger.error(f'File "{filename}"')	160	logger.error(f'File "{filename}"')