Miguel Barão / aprendizations

Download as
Browse Code »

Commit 2b709b19d9a93a1f83d4605e81509bdb38367489

Authored by Miguel Barão
1 parent 720ccbfa
Exists in master and in 1 other branch dev

fixed several errors in logging and updated messages 

all tornado code moved to serve.py
disallowed topic restart (avoid regenerating questions)
Showing 7 changed files with 129 additions and 107 deletions   Show diff stats
aprendizations/learnapp.py
  Diff comments   View file @2b709b1
... ... @@ -79,7 +79,7 @@ class LearnApp(object):
79 79  
80 80 errors = 0
81 81 for qref in self.factory:
82   - logger.debug(f'[sanity_check_questions] Checking "{qref}"...')
  82 + logger.debug(f'checking {qref}...')
83 83 try:
84 84 q = self.factory[qref].generate()
85 85 except Exception:
... ... @@ -208,7 +208,7 @@ class LearnApp(object):
208 208 finishtime=str(q['finish_time']),
209 209 student_id=uid,
210 210 topic_id=topic))
211   - logger.debug(f'[check_answer] Saved "{q["ref"]}" into database')
  211 + logger.debug(f'db insert answer of {q["ref"]}')
212 212  
213 213 if knowledge.topic_has_finished():
214 214 # finished topic, save into database
... ... @@ -222,7 +222,7 @@ class LearnApp(object):
222 222 .one_or_none()
223 223 if a is None:
224 224 # insert new studenttopic into database
225   - logger.debug('[check_answer] Database insert studenttopic')
  225 + logger.debug('db insert studenttopic')
226 226 t = s.query(Topic).get(topic)
227 227 u = s.query(Student).get(uid)
228 228 # association object
... ... @@ -231,14 +231,12 @@ class LearnApp(object):
231 231 u.topics.append(a)
232 232 else:
233 233 # update studenttopic in database
234   - logger.debug('[check_answer] Database update studenttopic')
  234 + logger.debug(f'db update studenttopic to level {level}')
235 235 a.level = level
236 236 a.date = date
237 237  
238 238 s.add(a)
239 239  
240   - logger.debug(f'[check_answer] Saved topic "{topic}" into database')
241   -
242 240 return q, action
243 241  
244 242 # ------------------------------------------------------------------------
... ... @@ -347,7 +345,7 @@ class LearnApp(object):
347 345 # Buils dictionary of question factories
348 346 # ------------------------------------------------------------------------
349 347 def make_factory(self) -> Dict[str, QFactory]:
350   - logger.info('Building questions factory...')
  348 + logger.info('Building questions factory:')
351 349 factory = {} # {'qref': QFactory()}
352 350 g = self.deps
353 351 for tref in g.nodes():
... ...
aprendizations/main.py
  Diff comments   View file @2b709b1
... ... @@ -4,34 +4,17 @@
4 4 import argparse
5 5 import logging
6 6 from os import environ, path
7   -import signal
8 7 import ssl
9 8 import sys
10 9  
11   -# third party libraries
12   -import tornado
13   -
14 10 # this project
15 11 from .learnapp import LearnApp, DatabaseUnusableError
16   -from .serve import WebApplication
  12 +from .serve import run_webserver
17 13 from .tools import load_yaml
18 14 from . import APP_NAME, APP_VERSION
19 15  
20 16  
21 17 # ----------------------------------------------------------------------------
22   -# Signal handler to catch Ctrl-C and abort server
23   -# ----------------------------------------------------------------------------
24   -def signal_handler(signal, frame):
25   - r = input(' --> Stop webserver? (yes/no) ').lower()
26   - if r == 'yes':
27   - tornado.ioloop.IOLoop.current().stop()
28   - logging.critical('Webserver stopped.')
29   - sys.exit(0)
30   - else:
31   - logging.info('Abort canceled...')
32   -
33   -
34   -# ----------------------------------------------------------------------------
35 18 def parse_cmdline_arguments():
36 19 argparser = argparse.ArgumentParser(
37 20 description='Server for online learning. Students and topics '
... ... @@ -91,7 +74,7 @@ def get_logger_config(debug=False):
91 74 'version': 1,
92 75 'formatters': {
93 76 'standard': {
94   - 'format': '%(asctime)s | %(levelname)-10s | %(message)s',
  77 + 'format': '%(asctime)s | %(levelname)-8s | %(message)s',
95 78 'datefmt': '%Y-%m-%d %H:%M:%S',
96 79 },
97 80 },
... ... @@ -115,14 +98,14 @@ def get_logger_config(debug=False):
115 98 'handlers': ['default'],
116 99 'level': level,
117 100 'propagate': False,
118   - } for module in ['learnapp', 'models', 'factory', 'questions',
119   - 'knowledge', 'tools']})
  101 + } for module in ['learnapp', 'models', 'factory', 'tools', 'serve',
  102 + 'questions', 'student']})
120 103  
121 104 return load_yaml(config_file, default=default_config)
122 105  
123 106  
124 107 # ----------------------------------------------------------------------------
125   -# Tornado web server
  108 +# Start application and webserver
126 109 # ----------------------------------------------------------------------------
127 110 def main():
128 111 # --- Commandline argument parsing
... ... @@ -144,34 +127,6 @@ def main():
144 127  
145 128 logging.info('====================== Start Logging ======================')
146 129  
147   - # --- start application
148   - logging.info('Starting App...')
149   - try:
150   - learnapp = LearnApp(arg.conffile, prefix=arg.prefix, db=arg.db,
151   - check=arg.check)
152   - except DatabaseUnusableError:
153   - logging.critical('Failed to start application.')
154   - print('--------------------------------------------------------------')
155   - print('Could not find a usable database. Use one of the follwing ')
156   - print('commands to initialize: ')
157   - print(' ')
158   - print(' initdb-aprendizations --admin # add admin ')
159   - print(' initdb-aprendizations -a 86 "Max Smart" # add student ')
160   - print(' initdb-aprendizations students.csv # add many students')
161   - print('--------------------------------------------------------------')
162   - sys.exit(1)
163   - except Exception:
164   - logging.critical('Failed to start application.')
165   - sys.exit(1)
166   -
167   - # --- create web application
168   - logging.info('Starting Web App (tornado)...')
169   - try:
170   - webapp = WebApplication(learnapp, debug=arg.debug)
171   - except Exception:
172   - logging.critical('Failed to start web application.')
173   - sys.exit(1)
174   -
175 130 # --- get SSL certificates
176 131 if 'XDG_DATA_HOME' in environ:
177 132 certs_dir = path.join(environ['XDG_DATA_HOME'], 'certs')
... ... @@ -197,34 +152,35 @@ def main():
197 152 print(' ')
198 153 print(f' {certs_dir:<62}')
199 154 print(' ')
  155 + print('(See README.md for more information) ')
200 156 print('--------------------------------------------------------------')
201 157 sys.exit(1)
  158 + else:
  159 + logging.info('SSL certificates loaded')
202 160  
203   - # --- create webserver
  161 + # --- start application
204 162 try:
205   - httpserver = tornado.httpserver.HTTPServer(webapp, ssl_options=ssl_ctx)
206   - except ValueError:
207   - logging.critical('Certificates cert.pem and privkey.pem not found')
  163 + learnapp = LearnApp(arg.conffile, prefix=arg.prefix, db=arg.db,
  164 + check=arg.check)
  165 + except DatabaseUnusableError:
  166 + logging.critical('Failed to start application.')
  167 + print('--------------------------------------------------------------')
  168 + print('Could not find a usable database. Use one of the follwing ')
  169 + print('commands to initialize: ')
  170 + print(' ')
  171 + print(' initdb-aprendizations --admin # add admin ')
  172 + print(' initdb-aprendizations -a 86 "Max Smart" # add student ')
  173 + print(' initdb-aprendizations students.csv # add many students')
  174 + print('--------------------------------------------------------------')
208 175 sys.exit(1)
209   -
210   - try:
211   - httpserver.listen(arg.port)
212   - except OSError:
213   - logging.critical(f'Cannot bind port {arg.port}. Already in use?')
  176 + except Exception:
  177 + logging.critical('Failed to start application.')
214 178 sys.exit(1)
  179 + else:
  180 + logging.info('Backend application started')
215 181  
216   - logging.info(f'Listening on port {arg.port}.')
217   -
218   - # --- run webserver
219   - signal.signal(signal.SIGINT, signal_handler)
220   - logging.info('Webserver running. (Ctrl-C to stop)')
221   -
222   - try:
223   - tornado.ioloop.IOLoop.current().start() # running...
224   - except Exception:
225   - logging.critical('Webserver stopped.')
226   - tornado.ioloop.IOLoop.current().stop()
227   - raise
  182 + # --- run webserver forever
  183 + run_webserver(app=learnapp, ssl=ssl_ctx, port=arg.port, debug=arg.debug)
228 184  
229 185  
230 186 # ----------------------------------------------------------------------------
... ...
aprendizations/questions.py
  Diff comments   View file @2b709b1
... ... @@ -461,7 +461,7 @@ class QFactory(object):
461 461 # i.e. a question object (radio, checkbox, ...).
462 462 # -----------------------------------------------------------------------
463 463 def generate(self) -> Question:
464   - logger.debug(f'[QFactory.generate] "{self.question["ref"]}"...')
  464 + logger.debug(f'generating {self.question["ref"]}...')
465 465 # Shallow copy so that script generated questions will not replace
466 466 # the original generators
467 467 q = self.question.copy()
... ... @@ -492,7 +492,7 @@ class QFactory(object):
492 492  
493 493 # -----------------------------------------------------------------------
494 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 496 # Shallow copy so that script generated questions will not replace
497 497 # the original generators
498 498 q = self.question.copy()
... ... @@ -520,5 +520,5 @@ class QFactory(object):
520 520 logger.error(f'Invalid type "{q["type"]}" in "{q["ref"]}"')
521 521 raise
522 522 else:
523   - logger.debug(f'[generate_async] Done instance of {q["ref"]}')
  523 + logger.debug('ok')
524 524 return qinstance
... ...
aprendizations/serve.py
  Diff comments   View file @2b709b1
... ... @@ -6,6 +6,8 @@ import functools
6 6 import logging.config
7 7 import mimetypes
8 8 from os import path
  9 +import signal
  10 +import sys
9 11 import uuid
10 12  
11 13 # third party libraries
... ... @@ -16,6 +18,9 @@ from tornado.escape import to_unicode
16 18 from .tools import md_to_html
17 19 from . import APP_NAME
18 20  
  21 +# setup logger for this module
  22 +logger = logging.getLogger(__name__)
  23 +
19 24  
20 25 # ----------------------------------------------------------------------------
21 26 # Decorator used to restrict access to the administrator only
... ... @@ -211,11 +216,11 @@ class FileHandler(BaseHandler):
211 216 with open(filepath, 'rb') as f:
212 217 data = f.read()
213 218 except FileNotFoundError:
214   - logging.error(f'File not found: {filepath}')
  219 + logger.error(f'File not found: {filepath}')
215 220 except PermissionError:
216   - logging.error(f'No permission: {filepath}')
  221 + logger.error(f'No permission: {filepath}')
217 222 except Exception:
218   - logging.error(f'Error reading: {filepath}')
  223 + logger.error(f'Error reading: {filepath}')
219 224 raise
220 225 else:
221 226 self.set_header("Content-Type", content_type)
... ... @@ -244,7 +249,7 @@ class QuestionHandler(BaseHandler):
244 249 # --- get question to render
245 250 @tornado.web.authenticated
246 251 def get(self):
247   - logging.debug('[QuestionHandler.get]')
  252 + logger.debug('[QuestionHandler.get]')
248 253 user = self.current_user
249 254 q = self.learn.get_current_question(user)
250 255  
... ... @@ -275,7 +280,7 @@ class QuestionHandler(BaseHandler):
275 280 # --- post answer, returns what to do next: shake, new_question, finished
276 281 @tornado.web.authenticated
277 282 async def post(self) -> None:
278   - logging.debug('[QuestionHandler.post]')
  283 + logger.debug('[QuestionHandler.post]')
279 284 user = self.current_user
280 285 answer = self.get_body_arguments('answer') # list
281 286  
... ... @@ -283,7 +288,7 @@ class QuestionHandler(BaseHandler):
283 288 answer_qid = self.get_body_arguments('qid')[0]
284 289 current_qid = self.learn.get_current_question_id(user)
285 290 if answer_qid != current_qid:
286   - logging.info(f'User {user} desynchronized questions')
  291 + logger.info(f'User {user} desynchronized questions')
287 292 self.write({
288 293 'method': 'invalid',
289 294 'params': {
... ... @@ -349,6 +354,59 @@ class QuestionHandler(BaseHandler):
349 354 'tries': q['tries'],
350 355 }
351 356 else:
352   - logging.error(f'Unknown action: {action}')
  357 + logger.error(f'Unknown action: {action}')
353 358  
354 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
... ...
aprendizations/student.py
  Diff comments   View file @2b709b1
... ... @@ -63,7 +63,7 @@ class StudentState(object):
63 63 'level': 0.0, # unlocked
64 64 'date': datetime.now()
65 65 }
66   - logger.debug(f'[unlock_topics] Unlocked "{topic}".')
  66 + logger.debug(f'unlocked "{topic}"')
67 67 # else: # lock this topic if deps do not satisfy min_level
68 68 # del self.state[topic]
69 69  
... ... @@ -73,15 +73,16 @@ class StudentState(object):
73 73 # current_question: the current question to be presented
74 74 # ------------------------------------------------------------------------
75 75 async def start_topic(self, topic: str):
76   - logger.debug(f'[start_topic] topic "{topic}"')
  76 + logger.debug(f'starting "{topic}"')
77 77  
78   - # if self.current_topic == topic:
79   - # logger.info('Restarting current topic is not allowed.')
80   - # return
  78 + # avoid regenerating questions in the middle of the current topic
  79 + if self.current_topic == topic:
  80 + logger.info('Restarting current topic is not allowed.')
  81 + return
81 82  
82 83 # do not allow locked topics
83 84 if self.is_locked(topic):
84   - logger.debug(f'[start_topic] topic "{topic}" is locked')
  85 + logger.debug(f'is locked "{topic}"')
85 86 return
86 87  
87 88 # starting new topic
... ... @@ -95,13 +96,13 @@ class StudentState(object):
95 96 questions = random.sample(t['questions'], k=k)
96 97 else:
97 98 questions = t['questions'][:k]
98   - logger.debug(f'[start_topic] questions: {", ".join(questions)}')
  99 + logger.debug(f'selected questions: {", ".join(questions)}')
99 100  
100 101 self.questions = [await self.factory[ref].generate_async()
101 102 for ref in questions]
102 103  
103 104 n = len(self.questions)
104   - logger.debug(f'[start_topic] generated {n} questions')
  105 + logger.debug(f'generated {n} questions')
105 106  
106 107 # get first question
107 108 self.next_question()
... ... @@ -112,7 +113,7 @@ class StudentState(object):
112 113 # The current topic is unchanged.
113 114 # ------------------------------------------------------------------------
114 115 def finish_topic(self):
115   - logger.debug(f'[finish_topic] current_topic {self.current_topic}')
  116 + logger.debug(f'finished {self.current_topic}')
116 117  
117 118 self.state[self.current_topic] = {
118 119 'date': datetime.now(),
... ... @@ -129,13 +130,12 @@ class StudentState(object):
129 130 # - if wrong, counts number of tries. If exceeded, moves on.
130 131 # ------------------------------------------------------------------------
131 132 async def check_answer(self, answer):
132   - logger.debug('[check_answer]')
133   -
134 133 q = self.current_question
135 134 q['answer'] = answer
136 135 q['finish_time'] = datetime.now()
  136 + logger.debug(f'checking answer of {q["ref"]}...')
137 137 await q.correct_async()
138   - logger.debug(f'[check_answer] Grade {q["grade"]:.2} in {q["ref"]}')
  138 + logger.debug(f'grade = {q["grade"]:.2}')
139 139  
140 140 if q['grade'] > 0.999:
141 141 self.correct_answers += 1
... ... @@ -151,7 +151,7 @@ class StudentState(object):
151 151 else:
152 152 action = 'wrong'
153 153 if self.current_question['append_wrong']:
154   - logger.debug('[check_answer] Wrong, append new instance')
  154 + logger.debug('wrong answer, append new question')
155 155 self.questions.append(self.factory[q['ref']].generate())
156 156 self.next_question()
157 157  
... ... @@ -172,7 +172,7 @@ class StudentState(object):
172 172 default_maxtries = self.deps.nodes[self.current_topic]['max_tries']
173 173 maxtries = self.current_question.get('max_tries', default_maxtries)
174 174 self.current_question['tries'] = maxtries
175   - logger.debug(f'[next_question] "{self.current_question["ref"]}"')
  175 + logger.debug(f'current_question = {self.current_question["ref"]}')
176 176  
177 177 return self.current_question # question or None
178 178  
... ...
config/logger-debug.yaml
  Diff comments   View file @2b709b1
... ... @@ -5,8 +5,8 @@ formatters:
5 5 void:
6 6 format: ''
7 7 standard:
8   - format: '%(asctime)s | %(levelname)-9s | %(name)-24s | %(thread)-15d | %(message)s'
9   - datefmt: '%H:%M:%S'
  8 + format: '%(asctime)s | %(thread)-15d | %(levelname)-8s | %(module)-10s | %(funcName)-20s | %(message)s'
  9 + # datefmt: '%H:%M:%S'
10 10  
11 11 handlers:
12 12 default:
... ... @@ -25,7 +25,7 @@ loggers:
25 25 level: 'DEBUG'
26 26 propagate: false
27 27  
28   - 'aprendizations.knowledge':
  28 + 'aprendizations.student':
29 29 handlers: ['default']
30 30 level: 'DEBUG'
31 31 propagate: false
... ... @@ -44,3 +44,8 @@ loggers:
44 44 handlers: ['default']
45 45 level: 'DEBUG'
46 46 propagate: false
  47 +
  48 + 'aprendizations.serve':
  49 + handlers: ['default']
  50 + level: 'DEBUG'
  51 + propagate: false
... ...
config/logger.yaml
  Diff comments   View file @2b709b1
... ... @@ -5,7 +5,7 @@ formatters:
5 5 void:
6 6 format: ''
7 7 standard:
8   - format: '%(asctime)s | %(thread)-15d | %(levelname)-9s | %(message)s'
  8 + format: '%(asctime)s | %(levelname)-8s | %(module)-10s | %(message)s'
9 9 datefmt: '%Y-%m-%d %H:%M:%S'
10 10  
11 11 handlers:
... ... @@ -25,7 +25,7 @@ loggers:
25 25 level: 'INFO'
26 26 propagate: false
27 27  
28   - 'aprendizations.knowledge':
  28 + 'aprendizations.student':
29 29 handlers: ['default']
30 30 level: 'INFO'
31 31 propagate: false
... ... @@ -44,3 +44,8 @@ loggers:
44 44 handlers: ['default']
45 45 level: 'INFO'
46 46 propagate: false
  47 +
  48 + 'aprendizations.serve':
  49 + handlers: ['default']
  50 + level: 'INFO'
  51 + propagate: false
... ...