Asynchronous run_script_async using asyncio.subprocess.

Asynchronous question generators. Asynchronous correction of textarea questions. Removes 'lines' option in textarea questions (unused in codemirror). The async implementations fixes errors with threading and sqlalchemy.

Asynchronous run_script_async using asyncio.subprocess.
Asynchronous question generators. Asynchronous correction of textarea questions. Removes 'lines' option in textarea questions (unused in codemirror). The async implementations fixes errors with threading and sqlalchemy.
Miguel Barão
1 parent c2abd6bf
Showing 10 changed files with 174 additions and 68 deletions Show diff stats
BUGS.md
aprendizations/knowledge.py
aprendizations/learnapp.py
aprendizations/questions.py
aprendizations/serve.py
aprendizations/templates/question-textarea.html
aprendizations/tools.py
demo/math/questions.yaml
demo/solar_system/correct-first_3_planets.py
demo/solar_system/questions.yaml
  
 # BUGS
  
+- 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 timout para o aluno saber a razao.
 - permitir configuracao para escolher entre static files locais ou remotos
 - sqlalchemy.pool.impl.NullPool: Exception during reset or similar
 sqlite3.ProgrammingError: SQLite objects created in a thread can only be used in that same thread.
@@ -58,7 +58,7 @@ class StudentKnowledge(object):
                         'level': 0.0,           # unlocked
                         'date': datetime.now()
                         }
-                    logger.debug(f'Unlocked "{topic}".')
+                    logger.debug(f'[unlock_topics] Unlocked "{topic}".')
                 # else:  # lock this topic if deps do not satisfy min_level
                 #     del self.state[topic]
  
@@ -68,7 +68,7 @@ class StudentKnowledge(object):
     #    current_question: the current question to be presented
     # ------------------------------------------------------------------------
     async def start_topic(self, topic):
-        logger.debug('StudentKnowledge.start_topic()')
+        logger.debug(f'[start_topic] topic "{topic}"')
  
         if self.current_topic == topic:
             logger.info('Restarting current topic is not allowed.')
@@ -76,7 +76,7 @@ class StudentKnowledge(object):
  
         # do not allow locked topics
         if self.is_locked(topic):
-            logger.debug(f'Topic {topic} is locked')
+            logger.debug(f'[start_topic] topic "{topic}" is locked')
             return False
  
         # starting new topic
@@ -90,23 +90,20 @@ class StudentKnowledge(object):
             questions = random.sample(t['questions'], k=k)
         else:
             questions = t['questions'][:k]
-        logger.debug(f'Questions: {", ".join(questions)}')
+        logger.debug(f'[start_topic] questions: {", ".join(questions)}')
  
-        # generate instances of questions
+        # synchronous
+        # self.questions = [self.factory[ref].generate()
+        #                   for ref in questions]
  
-        # synchronous:
-        # self.questions = [self.factory[ref].generate() for ref in questions]
-
-        # async:
-        loop = asyncio.get_running_loop()
-        generators = [loop.run_in_executor(None, self.factory[qref].generate)
-                      for qref in questions]
-        self.questions = await asyncio.gather(*generators)
+        # asynchronous:
+        self.questions = [await self.factory[ref].generate_async()
+                          for ref in questions]
  
         # get first question
         self.next_question()
  
-        logger.debug(f'Generated {len(self.questions)} questions')
+        logger.debug(f'[start_topic] generated {len(self.questions)} questions')
         return True
  
     # ------------------------------------------------------------------------
@@ -115,7 +112,7 @@ class StudentKnowledge(object):
     # The current topic is unchanged.
     # ------------------------------------------------------------------------
     def finish_topic(self):
-        logger.debug(f'StudentKnowledge.finish_topic({self.current_topic})')
+        logger.debug(f'[finish_topic] current_topic {self.current_topic}')
  
         self.state[self.current_topic] = {
             'date': datetime.now(),
@@ -132,13 +129,13 @@ class StudentKnowledge(object):
     #   - if wrong, counts number of tries. If exceeded, moves on.
     # ------------------------------------------------------------------------
     async def check_answer(self, answer):
-        logger.debug('StudentKnowledge.check_answer()')
+        logger.debug('[check_answer]')
  
         q = self.current_question
         q['answer'] = answer
         q['finish_time'] = datetime.now()
         await q.correct_async()
-        logger.debug(f'Grade {q["grade"]:.2} ({q["ref"]})')
+        logger.debug(f'[check_answer] Grade {q["grade"]:.2} in {q["ref"]}')
  
         if q['grade'] > 0.999:
             self.correct_answers += 1
@@ -154,7 +151,7 @@ class StudentKnowledge(object):
             else:
                 action = 'wrong'
                 if self.current_question['append_wrong']:
-                    logger.debug("Append new instance of question at the end")
+                    logger.debug('[check_answer] Wrong, append new instance')
                     self.questions.append(self.factory[q['ref']].generate())
                 self.next_question()
  
@@ -175,7 +172,7 @@ class StudentKnowledge(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 is "{self.current_question["ref"]}"')
+            logger.debug(f'[next_question] "{self.current_question["ref"]}"')
  
         return self.current_question  # question or None
  
@@ -75,7 +75,7 @@ class LearnApp(object):
  
         errors = 0
         for qref in self.factory:
-            logger.debug(f'Checking "{qref}"...')
+            logger.debug(f'[sanity_check_questions] Checking "{qref}"...')
             try:
                 q = self.factory[qref].generate()
             except Exception:
@@ -102,7 +102,7 @@ class LearnApp(object):
                         continue  # to next test
  
         if errors > 0:
-            logger.info(f'{errors:>6} errors found.')
+            logger.error(f'{errors:>6} errors found.')
             raise LearnException('Sanity checks')
         else:
             logger.info('No errors found.')
@@ -204,7 +204,7 @@ class LearnApp(object):
                 finishtime=str(q['finish_time']),
                 student_id=uid,
                 topic_id=topic))
-            logger.debug(f'Saved "{q["ref"]}" into database')
+            logger.debug(f'[check_answer] Saved "{q["ref"]}" into database')
  
         if knowledge.topic_has_finished():
             # finished topic, save into database
@@ -218,7 +218,7 @@ class LearnApp(object):
                     .one_or_none()
                 if a is None:
                     # insert new studenttopic into database
-                    logger.debug('Database insert new studenttopic')
+                    logger.debug('[check_answer] Database insert studenttopic')
                     t = s.query(Topic).get(topic)
                     u = s.query(Student).get(uid)
                     # association object
@@ -227,13 +227,13 @@ class LearnApp(object):
                     u.topics.append(a)
                 else:
                     # update studenttopic in database
-                    logger.debug('Database update studenttopic')
+                    logger.debug('[check_answer] Database update studenttopic')
                     a.level = level
                     a.date = date
  
                 s.add(a)
  
-            logger.debug(f'Saved topic "{topic}" into database')
+            logger.debug(f'[check_answer] Saved topic "{topic}" into database')
  
         return q, action
  
@@ -244,8 +244,8 @@ class LearnApp(object):
         student = self.online[uid]['state']
         try:
             await student.start_topic(topic)
-        except Exception:
-            logger.warning(f'User "{uid}" could not start topic "{topic}"')
+        except Exception as e:
+            logger.warning(f'User "{uid}" couldn\'t start "{topic}": {e}')
         else:
             logger.info(f'User "{uid}" started topic "{topic}"')
  
@@ -4,12 +4,11 @@ import random
 import re
 from os import path
 import logging
-import asyncio
 from typing import Any, Dict, NewType
 import uuid
  
 # this project
-from .tools import run_script
+from .tools import run_script, run_script_async
  
 # setup logger for this module
 logger = logging.getLogger(__name__)
@@ -50,8 +49,9 @@ class Question(dict):
         self['grade'] = 0.0
  
     async def correct_async(self) -> None:
-        loop = asyncio.get_running_loop()
-        await loop.run_in_executor(None, self.correct)
+        self.correct()
+        # loop = asyncio.get_running_loop()
+        # await loop.run_in_executor(None, self.correct)
  
     def set_defaults(self, d: QDict) -> None:
         'Add k:v pairs from default dict d for nonexistent keys'
@@ -305,7 +305,7 @@ class QuestionNumericInterval(Question):
                 answer = float(self['answer'].replace(',', '.', 1))
             except ValueError:
                 self['comments'] = ('A resposta tem de ser numérica, '
-                                    'por exemplo 12.345.')
+                                    'por exemplo `12.345`.')
                 self['grade'] = 0.0
             else:
                 self['grade'] = 1.0 if lower <= answer <= upper else 0.0
@@ -318,7 +318,6 @@ class QuestionTextArea(Question):
         text (str)
         correct (str with script to run)
         answer (None or an actual answer)
-        lines (int)
     '''
  
     # ------------------------------------------------------------------------
@@ -327,13 +326,12 @@ class QuestionTextArea(Question):
  
         self.set_defaults(QDict({
             'text': '',
-            'lines': 8,
-            'timeout': 5,  # seconds
+            'timeout': 5,   # seconds
             'correct': '',  # trying to execute this will fail => grade 0.0
             'args': []
             }))
  
-        self['correct'] = path.join(self['path'], self['correct'])   # FIXME
+        self['correct'] = path.join(self['path'], self['correct'])
  
     # ------------------------------------------------------------------------
     def correct(self) -> None:
@@ -347,7 +345,39 @@ class QuestionTextArea(Question):
                 timeout=self['timeout']
                 )
  
-            if isinstance(out, dict):
+            if out is None:
+                logger.warning(f'No grade after running "{self["correct"]}".')
+                self['grade'] = 0.0
+            elif isinstance(out, dict):
+                self['comments'] = out.get('comments', '')
+                try:
+                    self['grade'] = float(out['grade'])
+                except ValueError:
+                    logger.error(f'Output error in "{self["correct"]}".')
+                except KeyError:
+                    logger.error(f'No grade in "{self["correct"]}".')
+            else:
+                try:
+                    self['grade'] = float(out)
+                except (TypeError, ValueError):
+                    logger.error(f'Invalid grade in "{self["correct"]}".')
+
+    # ------------------------------------------------------------------------
+    async def correct_async(self) -> None:
+        super().correct()
+
+        if self['answer'] is not None:  # correct answer and parse yaml ouput
+            out = await run_script_async(
+                script=self['correct'],
+                args=self['args'],
+                stdin=self['answer'],
+                timeout=self['timeout']
+                )
+
+            if out is None:
+                logger.warning(f'No grade after running "{self["correct"]}".')
+                self['grade'] = 0.0
+            elif isinstance(out, dict):
                 self['comments'] = out.get('comments', '')
                 try:
                     self['grade'] = float(out['grade'])
@@ -372,7 +402,6 @@ class QuestionInformation(Question):
             }))
  
     # ------------------------------------------------------------------------
-    # can return negative values for wrong answers
     def correct(self) -> None:
         super().correct()
         self['grade'] = 1.0  # always "correct" but points should be zero!
@@ -400,7 +429,7 @@ class QuestionInformation(Question):
 #   # answer one question and correct it
 #   question['answer'] = 42          # set answer
 #   question.correct()               # correct answer
-#   print(question['grade'])         # print grade
+#   grade = question['grade']        # get grade
 # ===========================================================================
 class QFactory(object):
     # Depending on the type of question, a different question class will be
@@ -427,7 +456,7 @@ class QFactory(object):
     # i.e. a question object (radio, checkbox, ...).
     # -----------------------------------------------------------------------
     def generate(self) -> Question:
-        logger.debug(f'Generating "{self.question["ref"]}"...')
+        logger.debug(f'[generate] "{self.question["ref"]}"...')
         # Shallow copy so that script generated questions will not replace
         # the original generators
         q = self.question.copy()
@@ -439,7 +468,7 @@ class QFactory(object):
         if q['type'] == 'generator':
             logger.debug(f' \\_ Running "{q["script"]}".')
             q.setdefault('args', [])
-            q.setdefault('stdin', '')  # FIXME does not exist anymore?
+            q.setdefault('stdin', '')  # FIXME is it really necessary?
             script = path.join(q['path'], q['script'])
             out = run_script(script=script, args=q['args'], stdin=q['stdin'])
             q.update(out)
@@ -455,3 +484,36 @@ class QFactory(object):
             raise
         else:
             return qinstance
+
+    # -----------------------------------------------------------------------
+    async def generate_async(self) -> Question:
+        logger.debug(f'[generate_async] "{self.question["ref"]}"...')
+        # Shallow copy so that script generated questions will not replace
+        # the original generators
+        q = self.question.copy()
+        q['qid'] = str(uuid.uuid4())  # unique for each generated question
+
+        # If question is of generator type, an external program will be run
+        # which will print a valid question in yaml format to stdout. This
+        # output is then yaml parsed into a dictionary `q`.
+        if q['type'] == 'generator':
+            logger.debug(f' \\_ Running "{q["script"]}".')
+            q.setdefault('args', [])
+            q.setdefault('stdin', '')  # FIXME is it really necessary?
+            script = path.join(q['path'], q['script'])
+            out = await run_script_async(script=script, args=q['args'],
+                                         stdin=q['stdin'])
+            q.update(out)
+
+        # Finally we create an instance of Question()
+        try:
+            qinstance = self._types[q['type']](QDict(q))  # of matching class
+        except QuestionException as e:
+            logger.error(e)
+            raise e
+        except KeyError:
+            logger.error(f'Invalid type "{q["type"]}" in "{q["ref"]}"')
+            raise
+        else:
+            logger.debug(f'[generate_async] Done instance of {q["ref"]}')
+            return qinstance
 #!/usr/bin/env python3
  
 # python standard library
-import sys
+import argparse
+import asyncio
 import base64
-import uuid
+import functools
 import logging.config
-import argparse
 import mimetypes
+from os import path, environ
 import signal
-import functools
 import ssl
-import asyncio
-from os import path, environ
+import sys
+import uuid
+
  
 # third party libraries
 import tornado.ioloop
@@ -253,7 +254,7 @@ class QuestionHandler(BaseHandler):
     # --- get question to render
     @tornado.web.authenticated
     def get(self):
-        logging.debug('QuestionHandler.get()')
+        logging.debug('[QuestionHandler.get]')
         user = self.current_user
         q = self.learn.get_current_question(user)
  
@@ -284,7 +285,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()')
+        logging.debug('[QuestionHandler.post]')
         user = self.current_user
         answer = self.get_body_arguments('answer')  # list
  
@@ -2,7 +2,7 @@
  
 {% block answer %}
  
-<textarea class="form-control" rows="{{ question['lines'] }}" name="answer" id="code" autofocus>{{ question['answer'] or '' }}</textarea><br />
+<textarea class="form-control" name="answer" id="code" autofocus>{{ question['answer'] or '' }}</textarea><br />
 <input type="hidden" name="qid" value="{{ question['qid'] }}">
  
 <script>
  
 # python standard library
-from os import path
-import subprocess
+import asyncio
 import logging
+from os import path
 import re
+import subprocess
 from typing import Any, List
  
 # third party libraries
-import yaml
 import mistune
 from pygments import highlight
 from pygments.lexers import get_lexer_by_name
 from pygments.formatters import HtmlFormatter
+import yaml
+
  
 # setup logger for this module
 logger = logging.getLogger(__name__)
@@ -101,7 +103,7 @@ class HighlightRenderer(mistune.Renderer):
  
     def table(self, header, body):
         return '<table class="table table-sm"><thead class="thead-light">' \
-               + header + '</thead><tbody>' + body + "</tbody></table>"
+               + header + '</thead><tbody>' + body + '</tbody></table>'
  
     def image(self, src, title, alt):
         alt = mistune.escape(alt, quote=True)
@@ -168,7 +170,7 @@ def load_yaml(filename: str, default: Any = None) -&gt; Any:
 def run_script(script: str,
                args: List[str] = [],
                stdin: str = '',
-               timeout: int = 5) -> Any:
+               timeout: int = 2) -> Any:
  
     script = path.expanduser(script)
     try:
@@ -200,3 +202,41 @@ def run_script(script: str,
                 logger.error(f'Error parsing yaml output of "{script}"')
             else:
                 return output
+
+
+# ----------------------------------------------------------------------------
+# Same as above, but asynchronous
+# ----------------------------------------------------------------------------
+async def run_script_async(script: str,
+                           args: List[str] = [],
+                           stdin: str = '',
+                           timeout: int = 2) -> Any:
+
+    script = path.expanduser(script)
+    args = [str(a) for a in args]
+
+    p = await asyncio.create_subprocess_exec(
+        script, *args,
+        stdin=asyncio.subprocess.PIPE,
+        stdout=asyncio.subprocess.PIPE,
+        stderr=asyncio.subprocess.DEVNULL,
+        )
+
+    try:
+        stdout, stderr = await asyncio.wait_for(
+            p.communicate(input=stdin.encode('utf-8')),
+            timeout=timeout
+            )
+    except asyncio.TimeoutError:
+        logger.warning(f'Timeout {timeout}s running script "{script}".')
+        return
+
+    if p.returncode != 0:
+        logger.error(f'Return code {p.returncode} running "{script}".')
+    else:
+        try:
+            output = yaml.safe_load(stdout.decode('utf-8', 'ignore'))
+        except Exception:
+            logger.error(f'Error parsing yaml output of "{script}"')
+        else:
+            return output
@@ -16,6 +16,7 @@
     - $2\times(9-2\times 3)$
   correct: [1, 1, 0, 0, 0]
   choose: 3
+  max_tries: 1
   solution: |
     Colocando o 2 em evidência, obtém-se a resposta correcta $2\times(9 - 3)$
     ou $(9-3)\times 2$.
@@ -50,6 +51,7 @@
     - 12
     - 14
     - 1, a **unidade**
+  max_tries: 1
   solution: |
     O único número primo é o 13.
  
@@ -76,9 +78,10 @@
     números negativos são menores que os positivos.
  
 # ---------------------------------------------------------------------------
+# the program should print a question in yaml format. The args will be
+# sent as command line options when the program is run.
 - type: generator
   ref: overflow
   script: gen-multiples-of-3.py
   args: [11, 120]
-  # the program should print a question in yaml format. The args will be
-  # sent as command line options when the program is run.
+  choose: 3
@@ -2,26 +2,27 @@
  
 import re
 import sys
+import time
  
 s = sys.stdin.read()
  
-# set of words converted to lowercase
-answer = set(re.findall(r'[\w]+', s.lower()))
-answer.difference_update({'e', 'a', 'planeta', 'planetas'})  # ignore these
+ans = set(re.findall(r'[\w]+', s.lower()))  # convert answer to lowercase
+ans.difference_update({'e', 'a', 'o', 'planeta', 'planetas'})  # ignore words
  
 # correct set of planets
 planets = {'mercúrio', 'vénus', 'terra'}
  
-correct = set.intersection(answer, planets)     # the ones I got right
-wrong = set.difference(answer, planets)         # the ones I got wrong
+correct = set.intersection(ans, planets)     # the ones I got right
+wrong = set.difference(ans, planets)         # the ones I got wrong
  
 grade = (len(correct) - len(wrong)) / len(planets)
  
+comments = 'Certo' if grade == 1.0 else 'as iniciais dos planetas são M, V e T'
+
 out = f'''---
-grade: {grade}'''
+grade: {grade}
+comments: {comments}'''
  
-if grade < 1.0:
-    out += '\ncomments: Vou dar uma ajuda, as iniciais são M, V e T...'
+time.sleep(2)  # simulate computation time (may generate timeout)
  
 print(out)
-exit(0)
@@ -64,7 +64,6 @@
   # correct: correct-timeout.py
   # opcional
   answer: Vulcano, Krypton, Plutão
-  lines: 3
-  timeout: 50
+  timeout: 3
   solution: |
     Os 3 planetas mais perto do Sol são: Mercúrio, Vénus e Terra.
1	1
2	2	# BUGS
3	3
	4	+- quando termina topico devia apagar as perguntas todas (se falhar a gerar novo topico, aparecem perguntas do antigo)
	5	+- apos clicar no botao responder, inactivar o input (importante quando o tempo de correcção é grande)
	6	+- devia mostrar timout para o aluno saber a razao.
4	7	- permitir configuracao para escolher entre static files locais ou remotos
5	8	- sqlalchemy.pool.impl.NullPool: Exception during reset or similar
6	9	sqlite3.ProgrammingError: SQLite objects created in a thread can only be used in that same thread.
...	...
...	...	@@ -58,7 +58,7 @@ class StudentKnowledge(object):
58	58	'level': 0.0, # unlocked
59	59	'date': datetime.now()
60	60	}
61		- logger.debug(f'Unlocked "{topic}".')
	61	+ logger.debug(f'[unlock_topics] Unlocked "{topic}".')
62	62	# else: # lock this topic if deps do not satisfy min_level
63	63	# del self.state[topic]
64	64
...	...	@@ -68,7 +68,7 @@ class StudentKnowledge(object):
68	68	# current_question: the current question to be presented
69	69	# ------------------------------------------------------------------------
70	70	async def start_topic(self, topic):
71		- logger.debug('StudentKnowledge.start_topic()')
	71	+ logger.debug(f'[start_topic] topic "{topic}"')
72	72
73	73	if self.current_topic == topic:
74	74	logger.info('Restarting current topic is not allowed.')
...	...	@@ -76,7 +76,7 @@ class StudentKnowledge(object):
76	76
77	77	# do not allow locked topics
78	78	if self.is_locked(topic):
79		- logger.debug(f'Topic {topic} is locked')
	79	+ logger.debug(f'[start_topic] topic "{topic}" is locked')
80	80	return False
81	81
82	82	# starting new topic
...	...	@@ -90,23 +90,20 @@ class StudentKnowledge(object):
90	90	questions = random.sample(t['questions'], k=k)
91	91	else:
92	92	questions = t['questions'][:k]
93		- logger.debug(f'Questions: {", ".join(questions)}')
	93	+ logger.debug(f'[start_topic] questions: {", ".join(questions)}')
94	94
95		- # generate instances of questions
	95	+ # synchronous
	96	+ # self.questions = [self.factory[ref].generate()
	97	+ # for ref in questions]
96	98
97		- # synchronous:
98		- # self.questions = [self.factory[ref].generate() for ref in questions]
99		-
100		- # async:
101		- loop = asyncio.get_running_loop()
102		- generators = [loop.run_in_executor(None, self.factory[qref].generate)
103		- for qref in questions]
104		- self.questions = await asyncio.gather(*generators)
	99	+ # asynchronous:
	100	+ self.questions = [await self.factory[ref].generate_async()
	101	+ for ref in questions]
105	102
106	103	# get first question
107	104	self.next_question()
108	105
109		- logger.debug(f'Generated {len(self.questions)} questions')
	106	+ logger.debug(f'[start_topic] generated {len(self.questions)} questions')
110	107	return True
111	108
112	109	# ------------------------------------------------------------------------
...	...	@@ -115,7 +112,7 @@ class StudentKnowledge(object):
115	112	# The current topic is unchanged.
116	113	# ------------------------------------------------------------------------
117	114	def finish_topic(self):
118		- logger.debug(f'StudentKnowledge.finish_topic({self.current_topic})')
	115	+ logger.debug(f'[finish_topic] current_topic {self.current_topic}')
119	116
120	117	self.state[self.current_topic] = {
121	118	'date': datetime.now(),
...	...	@@ -132,13 +129,13 @@ class StudentKnowledge(object):
132	129	# - if wrong, counts number of tries. If exceeded, moves on.
133	130	# ------------------------------------------------------------------------
134	131	async def check_answer(self, answer):
135		- logger.debug('StudentKnowledge.check_answer()')
	132	+ logger.debug('[check_answer]')
136	133
137	134	q = self.current_question
138	135	q['answer'] = answer
139	136	q['finish_time'] = datetime.now()
140	137	await q.correct_async()
141		- logger.debug(f'Grade {q["grade"]:.2} ({q["ref"]})')
	138	+ logger.debug(f'[check_answer] Grade {q["grade"]:.2} in {q["ref"]}')
142	139
143	140	if q['grade'] > 0.999:
144	141	self.correct_answers += 1
...	...	@@ -154,7 +151,7 @@ class StudentKnowledge(object):
154	151	else:
155	152	action = 'wrong'
156	153	if self.current_question['append_wrong']:
157		- logger.debug("Append new instance of question at the end")
	154	+ logger.debug('[check_answer] Wrong, append new instance')
158	155	self.questions.append(self.factory[q['ref']].generate())
159	156	self.next_question()
160	157
...	...	@@ -175,7 +172,7 @@ class StudentKnowledge(object):
175	172	default_maxtries = self.deps.nodes[self.current_topic]['max_tries']
176	173	maxtries = self.current_question.get('max_tries', default_maxtries)
177	174	self.current_question['tries'] = maxtries
178		- logger.debug(f'Next question is "{self.current_question["ref"]}"')
	175	+ logger.debug(f'[next_question] "{self.current_question["ref"]}"')
179	176
180	177	return self.current_question # question or None
181	178
...	...
...	...	@@ -75,7 +75,7 @@ class LearnApp(object):
75	75
76	76	errors = 0
77	77	for qref in self.factory:
78		- logger.debug(f'Checking "{qref}"...')
	78	+ logger.debug(f'[sanity_check_questions] Checking "{qref}"...')
79	79	try:
80	80	q = self.factory[qref].generate()
81	81	except Exception:
...	...	@@ -102,7 +102,7 @@ class LearnApp(object):
102	102	continue # to next test
103	103
104	104	if errors > 0:
105		- logger.info(f'{errors:>6} errors found.')
	105	+ logger.error(f'{errors:>6} errors found.')
106	106	raise LearnException('Sanity checks')
107	107	else:
108	108	logger.info('No errors found.')
...	...	@@ -204,7 +204,7 @@ class LearnApp(object):
204	204	finishtime=str(q['finish_time']),
205	205	student_id=uid,
206	206	topic_id=topic))
207		- logger.debug(f'Saved "{q["ref"]}" into database')
	207	+ logger.debug(f'[check_answer] Saved "{q["ref"]}" into database')
208	208
209	209	if knowledge.topic_has_finished():
210	210	# finished topic, save into database
...	...	@@ -218,7 +218,7 @@ class LearnApp(object):
218	218	.one_or_none()
219	219	if a is None:
220	220	# insert new studenttopic into database
221		- logger.debug('Database insert new studenttopic')
	221	+ logger.debug('[check_answer] Database insert studenttopic')
222	222	t = s.query(Topic).get(topic)
223	223	u = s.query(Student).get(uid)
224	224	# association object
...	...	@@ -227,13 +227,13 @@ class LearnApp(object):
227	227	u.topics.append(a)
228	228	else:
229	229	# update studenttopic in database
230		- logger.debug('Database update studenttopic')
	230	+ logger.debug('[check_answer] Database update studenttopic')
231	231	a.level = level
232	232	a.date = date
233	233
234	234	s.add(a)
235	235
236		- logger.debug(f'Saved topic "{topic}" into database')
	236	+ logger.debug(f'[check_answer] Saved topic "{topic}" into database')
237	237
238	238	return q, action
239	239
...	...	@@ -244,8 +244,8 @@ class LearnApp(object):
244	244	student = self.online[uid]['state']
245	245	try:
246	246	await student.start_topic(topic)
247		- except Exception:
248		- logger.warning(f'User "{uid}" could not start topic "{topic}"')
	247	+ except Exception as e:
	248	+ logger.warning(f'User "{uid}" couldn\'t start "{topic}": {e}')
249	249	else:
250	250	logger.info(f'User "{uid}" started topic "{topic}"')
251	251
...	...
...	...	@@ -4,12 +4,11 @@ import random
4	4	import re
5	5	from os import path
6	6	import logging
7		-import asyncio
8	7	from typing import Any, Dict, NewType
9	8	import uuid
10	9
11	10	# this project
12		-from .tools import run_script
	11	+from .tools import run_script, run_script_async
13	12
14	13	# setup logger for this module
15	14	logger = logging.getLogger(__name__)
...	...	@@ -50,8 +49,9 @@ class Question(dict):
50	49	self['grade'] = 0.0
51	50
52	51	async def correct_async(self) -> None:
53		- loop = asyncio.get_running_loop()
54		- await loop.run_in_executor(None, self.correct)
	52	+ self.correct()
	53	+ # loop = asyncio.get_running_loop()
	54	+ # await loop.run_in_executor(None, self.correct)
55	55
56	56	def set_defaults(self, d: QDict) -> None:
57	57	'Add k:v pairs from default dict d for nonexistent keys'
...	...	@@ -305,7 +305,7 @@ class QuestionNumericInterval(Question):
305	305	answer = float(self['answer'].replace(',', '.', 1))
306	306	except ValueError:
307	307	self['comments'] = ('A resposta tem de ser numérica, '
308		- 'por exemplo 12.345.')
	308	+ 'por exemplo `12.345`.')
309	309	self['grade'] = 0.0
310	310	else:
311	311	self['grade'] = 1.0 if lower <= answer <= upper else 0.0
...	...	@@ -318,7 +318,6 @@ class QuestionTextArea(Question):
318	318	text (str)
319	319	correct (str with script to run)
320	320	answer (None or an actual answer)
321		- lines (int)
322	321	'''
323	322
324	323	# ------------------------------------------------------------------------
...	...	@@ -327,13 +326,12 @@ class QuestionTextArea(Question):
327	326
328	327	self.set_defaults(QDict({
329	328	'text': '',
330		- 'lines': 8,
331		- 'timeout': 5, # seconds
	329	+ 'timeout': 5, # seconds
332	330	'correct': '', # trying to execute this will fail => grade 0.0
333	331	'args': []
334	332	}))
335	333
336		- self['correct'] = path.join(self['path'], self['correct']) # FIXME
	334	+ self['correct'] = path.join(self['path'], self['correct'])
337	335
338	336	# ------------------------------------------------------------------------
339	337	def correct(self) -> None:
...	...	@@ -347,7 +345,39 @@ class QuestionTextArea(Question):
347	345	timeout=self['timeout']
348	346	)
349	347
350		- if isinstance(out, dict):
	348	+ if out is None:
	349	+ logger.warning(f'No grade after running "{self["correct"]}".')
	350	+ self['grade'] = 0.0
	351	+ elif isinstance(out, dict):
	352	+ self['comments'] = out.get('comments', '')
	353	+ try:
	354	+ self['grade'] = float(out['grade'])
	355	+ except ValueError:
	356	+ logger.error(f'Output error in "{self["correct"]}".')
	357	+ except KeyError:
	358	+ logger.error(f'No grade in "{self["correct"]}".')
	359	+ else:
	360	+ try:
	361	+ self['grade'] = float(out)
	362	+ except (TypeError, ValueError):
	363	+ logger.error(f'Invalid grade in "{self["correct"]}".')
	364	+
	365	+ # ------------------------------------------------------------------------
	366	+ async def correct_async(self) -> None:
	367	+ super().correct()
	368	+
	369	+ if self['answer'] is not None: # correct answer and parse yaml ouput
	370	+ out = await run_script_async(
	371	+ script=self['correct'],
	372	+ args=self['args'],
	373	+ stdin=self['answer'],
	374	+ timeout=self['timeout']
	375	+ )
	376	+
	377	+ if out is None:
	378	+ logger.warning(f'No grade after running "{self["correct"]}".')
	379	+ self['grade'] = 0.0
	380	+ elif isinstance(out, dict):
351	381	self['comments'] = out.get('comments', '')
352	382	try:
353	383	self['grade'] = float(out['grade'])
...	...	@@ -372,7 +402,6 @@ class QuestionInformation(Question):
372	402	}))
373	403
374	404	# ------------------------------------------------------------------------
375		- # can return negative values for wrong answers
376	405	def correct(self) -> None:
377	406	super().correct()
378	407	self['grade'] = 1.0 # always "correct" but points should be zero!
...	...	@@ -400,7 +429,7 @@ class QuestionInformation(Question):
400	429	# # answer one question and correct it
401	430	# question['answer'] = 42 # set answer
402	431	# question.correct() # correct answer
403		-# print(question['grade']) # print grade
	432	+# grade = question['grade'] # get grade
404	433	# ===========================================================================
405	434	class QFactory(object):
406	435	# Depending on the type of question, a different question class will be
...	...	@@ -427,7 +456,7 @@ class QFactory(object):
427	456	# i.e. a question object (radio, checkbox, ...).
428	457	# -----------------------------------------------------------------------
429	458	def generate(self) -> Question:
430		- logger.debug(f'Generating "{self.question["ref"]}"...')
	459	+ logger.debug(f'[generate] "{self.question["ref"]}"...')
431	460	# Shallow copy so that script generated questions will not replace
432	461	# the original generators
433	462	q = self.question.copy()
...	...	@@ -439,7 +468,7 @@ class QFactory(object):
439	468	if q['type'] == 'generator':
440	469	logger.debug(f' \\_ Running "{q["script"]}".')
441	470	q.setdefault('args', [])
442		- q.setdefault('stdin', '') # FIXME does not exist anymore?
	471	+ q.setdefault('stdin', '') # FIXME is it really necessary?
443	472	script = path.join(q['path'], q['script'])
444	473	out = run_script(script=script, args=q['args'], stdin=q['stdin'])
445	474	q.update(out)
...	...	@@ -455,3 +484,36 @@ class QFactory(object):
455	484	raise
456	485	else:
457	486	return qinstance
	487	+
	488	+ # -----------------------------------------------------------------------
	489	+ async def generate_async(self) -> Question:
	490	+ logger.debug(f'[generate_async] "{self.question["ref"]}"...')
	491	+ # Shallow copy so that script generated questions will not replace
	492	+ # the original generators
	493	+ q = self.question.copy()
	494	+ q['qid'] = str(uuid.uuid4()) # unique for each generated question
	495	+
	496	+ # If question is of generator type, an external program will be run
	497	+ # which will print a valid question in yaml format to stdout. This
	498	+ # output is then yaml parsed into a dictionary `q`.
	499	+ if q['type'] == 'generator':
	500	+ logger.debug(f' \\_ Running "{q["script"]}".')
	501	+ q.setdefault('args', [])
	502	+ q.setdefault('stdin', '') # FIXME is it really necessary?
	503	+ script = path.join(q['path'], q['script'])
	504	+ out = await run_script_async(script=script, args=q['args'],
	505	+ stdin=q['stdin'])
	506	+ q.update(out)
	507	+
	508	+ # Finally we create an instance of Question()
	509	+ try:
	510	+ qinstance = self._types[q['type']](QDict(q)) # of matching class
	511	+ except QuestionException as e:
	512	+ logger.error(e)
	513	+ raise e
	514	+ except KeyError:
	515	+ logger.error(f'Invalid type "{q["type"]}" in "{q["ref"]}"')
	516	+ raise
	517	+ else:
	518	+ logger.debug(f'[generate_async] Done instance of {q["ref"]}')
	519	+ return qinstance
...	...
1	1	#!/usr/bin/env python3
2	2
3	3	# python standard library
4		-import sys
	4	+import argparse
	5	+import asyncio
5	6	import base64
6		-import uuid
	7	+import functools
7	8	import logging.config
8		-import argparse
9	9	import mimetypes
	10	+from os import path, environ
10	11	import signal
11		-import functools
12	12	import ssl
13		-import asyncio
14		-from os import path, environ
	13	+import sys
	14	+import uuid
	15	+
15	16
16	17	# third party libraries
17	18	import tornado.ioloop
...	...	@@ -253,7 +254,7 @@ class QuestionHandler(BaseHandler):
253	254	# --- get question to render
254	255	@tornado.web.authenticated
255	256	def get(self):
256		- logging.debug('QuestionHandler.get()')
	257	+ logging.debug('[QuestionHandler.get]')
257	258	user = self.current_user
258	259	q = self.learn.get_current_question(user)
259	260
...	...	@@ -284,7 +285,7 @@ class QuestionHandler(BaseHandler):
284	285	# --- post answer, returns what to do next: shake, new_question, finished
285	286	@tornado.web.authenticated
286	287	async def post(self) -> None:
287		- logging.debug('QuestionHandler.post()')
	288	+ logging.debug('[QuestionHandler.post]')
288	289	user = self.current_user
289	290	answer = self.get_body_arguments('answer') # list
290	291
...	...
...	...	@@ -2,7 +2,7 @@
2	2
3	3	{% block answer %}
4	4
5		-<textarea class="form-control" rows="{{ question['lines'] }}" name="answer" id="code" autofocus>{{ question['answer'] or '' }}</textarea><br />
	5	+<textarea class="form-control" name="answer" id="code" autofocus>{{ question['answer'] or '' }}</textarea><br />
6	6	<input type="hidden" name="qid" value="{{ question['qid'] }}">
7	7
8	8	<script>
...	...
1	1
2	2	# python standard library
3		-from os import path
4		-import subprocess
	3	+import asyncio
5	4	import logging
	5	+from os import path
6	6	import re
	7	+import subprocess
7	8	from typing import Any, List
8	9
9	10	# third party libraries
10		-import yaml
11	11	import mistune
12	12	from pygments import highlight
13	13	from pygments.lexers import get_lexer_by_name
14	14	from pygments.formatters import HtmlFormatter
	15	+import yaml
	16	+
15	17
16	18	# setup logger for this module
17	19	logger = logging.getLogger(__name__)
...	...	@@ -101,7 +103,7 @@ class HighlightRenderer(mistune.Renderer):
101	103
102	104	def table(self, header, body):
103	105	return '<table class="table table-sm"><thead class="thead-light">' \
104		- + header + '</thead><tbody>' + body + "</tbody></table>"
	106	+ + header + '</thead><tbody>' + body + '</tbody></table>'
105	107
106	108	def image(self, src, title, alt):
107	109	alt = mistune.escape(alt, quote=True)
...	...	@@ -168,7 +170,7 @@ def load_yaml(filename: str, default: Any = None) -> Any:
168	170	def run_script(script: str,
169	171	args: List[str] = [],
170	172	stdin: str = '',
171		- timeout: int = 5) -> Any:
	173	+ timeout: int = 2) -> Any:
172	174
173	175	script = path.expanduser(script)
174	176	try:
...	...	@@ -200,3 +202,41 @@ def run_script(script: str,
200	202	logger.error(f'Error parsing yaml output of "{script}"')
201	203	else:
202	204	return output
	205	+
	206	+
	207	+# ----------------------------------------------------------------------------
	208	+# Same as above, but asynchronous
	209	+# ----------------------------------------------------------------------------
	210	+async def run_script_async(script: str,
	211	+ args: List[str] = [],
	212	+ stdin: str = '',
	213	+ timeout: int = 2) -> Any:
	214	+
	215	+ script = path.expanduser(script)
	216	+ args = [str(a) for a in args]
	217	+
	218	+ p = await asyncio.create_subprocess_exec(
	219	+ script, *args,
	220	+ stdin=asyncio.subprocess.PIPE,
	221	+ stdout=asyncio.subprocess.PIPE,
	222	+ stderr=asyncio.subprocess.DEVNULL,
	223	+ )
	224	+
	225	+ try:
	226	+ stdout, stderr = await asyncio.wait_for(
	227	+ p.communicate(input=stdin.encode('utf-8')),
	228	+ timeout=timeout
	229	+ )
	230	+ except asyncio.TimeoutError:
	231	+ logger.warning(f'Timeout {timeout}s running script "{script}".')
	232	+ return
	233	+
	234	+ if p.returncode != 0:
	235	+ logger.error(f'Return code {p.returncode} running "{script}".')
	236	+ else:
	237	+ try:
	238	+ output = yaml.safe_load(stdout.decode('utf-8', 'ignore'))
	239	+ except Exception:
	240	+ logger.error(f'Error parsing yaml output of "{script}"')
	241	+ else:
	242	+ return output
...	...
...	...	@@ -16,6 +16,7 @@
16	16	- $2\times(9-2\times 3)$
17	17	correct: [1, 1, 0, 0, 0]
18	18	choose: 3
	19	+ max_tries: 1
19	20	solution: \|
20	21	Colocando o 2 em evidência, obtém-se a resposta correcta $2\times(9 - 3)$
21	22	ou $(9-3)\times 2$.
...	...	@@ -50,6 +51,7 @@
50	51	- 12
51	52	- 14
52	53	- 1, a unidade
	54	+ max_tries: 1
53	55	solution: \|
54	56	O único número primo é o 13.
55	57
...	...	@@ -76,9 +78,10 @@
76	78	números negativos são menores que os positivos.
77	79
78	80	# ---------------------------------------------------------------------------
	81	+# the program should print a question in yaml format. The args will be
	82	+# sent as command line options when the program is run.
79	83	- type: generator
80	84	ref: overflow
81	85	script: gen-multiples-of-3.py
82	86	args: [11, 120]
83		- # the program should print a question in yaml format. The args will be
84		- # sent as command line options when the program is run.
	87	+ choose: 3
...	...
...	...	@@ -2,26 +2,27 @@
2	2
3	3	import re
4	4	import sys
	5	+import time
5	6
6	7	s = sys.stdin.read()
7	8
8		-# set of words converted to lowercase
9		-answer = set(re.findall(r'[\w]+', s.lower()))
10		-answer.difference_update({'e', 'a', 'planeta', 'planetas'}) # ignore these
	9	+ans = set(re.findall(r'[\w]+', s.lower())) # convert answer to lowercase
	10	+ans.difference_update({'e', 'a', 'o', 'planeta', 'planetas'}) # ignore words
11	11
12	12	# correct set of planets
13	13	planets = {'mercúrio', 'vénus', 'terra'}
14	14
15		-correct = set.intersection(answer, planets) # the ones I got right
16		-wrong = set.difference(answer, planets) # the ones I got wrong
	15	+correct = set.intersection(ans, planets) # the ones I got right
	16	+wrong = set.difference(ans, planets) # the ones I got wrong
17	17
18	18	grade = (len(correct) - len(wrong)) / len(planets)
19	19
	20	+comments = 'Certo' if grade == 1.0 else 'as iniciais dos planetas são M, V e T'
	21	+
20	22	out = f'''---
21		-grade: {grade}'''
	23	+grade: {grade}
	24	+comments: {comments}'''
22	25
23		-if grade < 1.0:
24		- out += '\ncomments: Vou dar uma ajuda, as iniciais são M, V e T...'
	26	+time.sleep(2) # simulate computation time (may generate timeout)
25	27
26	28	print(out)
27		-exit(0)
...	...
...	...	@@ -64,7 +64,6 @@
64	64	# correct: correct-timeout.py
65	65	# opcional
66	66	answer: Vulcano, Krypton, Plutão
67		- lines: 3
68		- timeout: 50
	67	+ timeout: 3
69	68	solution: \|
70	69	Os 3 planetas mais perto do Sol são: Mercúrio, Vénus e Terra.
...	...