From 32253510d1892a14357a766aa97e23a9cbc3da73 Mon Sep 17 00:00:00 2001 From: Victor Shnayder Date: Tue, 31 Jul 2012 19:37:53 -0400 Subject: [PATCH] Import error cleanup * call error tracker when needed * remove duplicate logging--just add info and re-raise * xml modulestore uses error tracker to capture load errors * add unstyled list of import errors to courseware homepage! --- .../lib/xmodule/xmodule/backcompat_module.py | 5 +- common/lib/xmodule/xmodule/capa_module.py | 25 ++++++--- common/lib/xmodule/xmodule/course_module.py | 14 +++-- common/lib/xmodule/xmodule/errortracker.py | 10 ++-- common/lib/xmodule/xmodule/html_module.py | 5 +- .../xmodule/xmodule/modulestore/__init__.py | 13 +++++ common/lib/xmodule/xmodule/modulestore/xml.py | 54 ++++++++++++------- common/lib/xmodule/xmodule/x_module.py | 5 +- lms/djangoapps/courseware/courses.py | 1 + lms/djangoapps/courseware/views.py | 15 ++++-- lms/templates/courseware.html | 7 +++ 11 files changed, 115 insertions(+), 39 deletions(-) diff --git a/common/lib/xmodule/xmodule/backcompat_module.py b/common/lib/xmodule/xmodule/backcompat_module.py index 7ace342d1b..c49f23b99e 100644 --- a/common/lib/xmodule/xmodule/backcompat_module.py +++ b/common/lib/xmodule/xmodule/backcompat_module.py @@ -35,12 +35,13 @@ def process_includes(fn): # insert new XML into tree in place of include parent.insert(parent.index(next_include), incxml) except Exception: - # Log error and work around it + # Log error msg = "Error in problem xml include: %s" % ( etree.tostring(next_include, pretty_print=True)) - + # tell the tracker system.error_tracker(msg) + # work around parent = next_include.getparent() errorxml = etree.Element('error') messagexml = etree.SubElement(errorxml, 'message') diff --git a/common/lib/xmodule/xmodule/capa_module.py b/common/lib/xmodule/xmodule/capa_module.py index 2fae8b94e2..eed2cf3ac7 100644 --- a/common/lib/xmodule/xmodule/capa_module.py +++ b/common/lib/xmodule/xmodule/capa_module.py @@ -5,6 +5,7 @@ import json import logging import traceback import re +import sys from datetime import timedelta from lxml import etree @@ -91,7 +92,8 @@ class CapaModule(XModule): display_due_date_string = self.metadata.get('due', None) if display_due_date_string is not None: self.display_due_date = dateutil.parser.parse(display_due_date_string) - #log.debug("Parsed " + display_due_date_string + " to " + str(self.display_due_date)) + #log.debug("Parsed " + display_due_date_string + + # " to " + str(self.display_due_date)) else: self.display_due_date = None @@ -99,7 +101,8 @@ class CapaModule(XModule): if grace_period_string is not None and self.display_due_date: self.grace_period = parse_timedelta(grace_period_string) self.close_date = self.display_due_date + self.grace_period - #log.debug("Then parsed " + grace_period_string + " to closing date" + str(self.close_date)) + #log.debug("Then parsed " + grace_period_string + + # " to closing date" + str(self.close_date)) else: self.grace_period = None self.close_date = self.display_due_date @@ -138,10 +141,16 @@ class CapaModule(XModule): try: self.lcp = LoncapaProblem(self.definition['data'], self.location.html_id(), instance_state, seed=seed, system=self.system) - except Exception: - msg = 'cannot create LoncapaProblem %s' % self.location.url() - log.exception(msg) + except Exception as err: + msg = 'cannot create LoncapaProblem {loc}: {err}'.format( + loc=self.location.url(), err=err) + # TODO (vshnayder): do modules need error handlers too? + # We shouldn't be switching on DEBUG. if self.system.DEBUG: + log.error(msg) + # TODO (vshnayder): This logic should be general, not here--and may + # want to preserve the data instead of replacing it. + # e.g. in the CMS msg = '

%s

' % msg.replace('<', '<') msg += '

%s

' % traceback.format_exc().replace('<', '<') # create a dummy problem with error message instead of failing @@ -152,7 +161,8 @@ class CapaModule(XModule): problem_text, self.location.html_id(), instance_state, seed=seed, system=self.system) else: - raise + # add extra info and raise + raise Exception(msg), None, sys.exc_info()[2] @property def rerandomize(self): @@ -191,6 +201,7 @@ class CapaModule(XModule): try: return Progress(score, total) except Exception as err: + # TODO (vshnayder): why is this still here? still needed? if self.system.DEBUG: return None raise @@ -210,6 +221,7 @@ class CapaModule(XModule): try: html = self.lcp.get_html() except Exception, err: + # TODO (vshnayder): another switch on DEBUG. if self.system.DEBUG: log.exception(err) msg = ( @@ -561,6 +573,7 @@ class CapaDescriptor(RawDescriptor): 'problems/' + path[8:], path[8:], ] + @classmethod def split_to_file(cls, xml_object): '''Problems always written in their own files''' diff --git a/common/lib/xmodule/xmodule/course_module.py b/common/lib/xmodule/xmodule/course_module.py index 7e0019205e..acdc574220 100644 --- a/common/lib/xmodule/xmodule/course_module.py +++ b/common/lib/xmodule/xmodule/course_module.py @@ -20,15 +20,22 @@ class CourseDescriptor(SequenceDescriptor): self._grader = None self._grade_cutoffs = None + msg = None try: self.start = time.strptime(self.metadata["start"], "%Y-%m-%dT%H:%M") except KeyError: self.start = time.gmtime(0) #The epoch - log.critical("Course loaded without a start date. %s", self.id) + msg = "Course loaded without a start date. id = %s" % self.id + log.critical(msg) except ValueError as e: self.start = time.gmtime(0) #The epoch - log.critical("Course loaded with a bad start date. %s '%s'", - self.id, e) + msg = "Course loaded with a bad start date. %s '%s'" % (self.id, e) + log.critical(msg) + + # Don't call the tracker from the exception handler. + if msg is not None: + system.error_tracker(msg) + def has_started(self): return time.gmtime() > self.start @@ -104,3 +111,4 @@ class CourseDescriptor(SequenceDescriptor): @property def org(self): return self.location.org + diff --git a/common/lib/xmodule/xmodule/errortracker.py b/common/lib/xmodule/xmodule/errortracker.py index 8dd893e814..09c04c061c 100644 --- a/common/lib/xmodule/xmodule/errortracker.py +++ b/common/lib/xmodule/xmodule/errortracker.py @@ -1,17 +1,21 @@ import logging import sys +from collections import namedtuple + log = logging.getLogger(__name__) +ErrorLog = namedtuple('ErrorLog', 'tracker errors') + def in_exception_handler(): '''Is there an active exception?''' return sys.exc_info() != (None, None, None) def make_error_tracker(): - '''Return a tuple (logger, error_list), where + '''Return an ErrorLog (named tuple), with fields (tracker, errors), where the logger appends a tuple (message, exc_info=None) - to the error_list on every call. + to the errors on every call. error_list is a simple list. If the caller messes with it, info will be lost. @@ -26,7 +30,7 @@ def make_error_tracker(): errors.append((msg, exc_info)) - return (error_tracker, errors) + return ErrorLog(error_tracker, errors) def null_error_tracker(msg): '''A dummy error tracker that just ignores the messages''' diff --git a/common/lib/xmodule/xmodule/html_module.py b/common/lib/xmodule/xmodule/html_module.py index 996d3c4ead..165c402487 100644 --- a/common/lib/xmodule/xmodule/html_module.py +++ b/common/lib/xmodule/xmodule/html_module.py @@ -2,6 +2,7 @@ import copy from fs.errors import ResourceNotFoundError import logging import os +import sys from lxml import etree from xmodule.x_module import XModule @@ -95,8 +96,8 @@ class HtmlDescriptor(XmlDescriptor, EditingDescriptor): except (ResourceNotFoundError) as err: msg = 'Unable to load file contents at path {0}: {1} '.format( filepath, err) - log.error(msg) - raise + # add more info and re-raise + raise Exception(msg), None, sys.exc_info()[2] @classmethod def split_to_file(cls, xml_object): diff --git a/common/lib/xmodule/xmodule/modulestore/__init__.py b/common/lib/xmodule/xmodule/modulestore/__init__.py index a0167d781b..7241179d8e 100644 --- a/common/lib/xmodule/xmodule/modulestore/__init__.py +++ b/common/lib/xmodule/xmodule/modulestore/__init__.py @@ -213,6 +213,18 @@ class ModuleStore(object): """ raise NotImplementedError + def get_item_errors(self, location): + """ + Return a list of (msg, exception-or-None) errors that the modulestore + encountered when loading the item at location. + + location : something that can be passed to Location + + Raises the same exceptions as get_item if the location isn't found or + isn't fully specified. + """ + raise NotImplementedError + def get_items(self, location, depth=0): """ Returns a list of XModuleDescriptor instances for the items @@ -269,6 +281,7 @@ class ModuleStore(object): ''' raise NotImplementedError + def get_parent_locations(self, location): '''Find all locations that are the parents of this location. Needed for path_to_location(). diff --git a/common/lib/xmodule/xmodule/modulestore/xml.py b/common/lib/xmodule/xmodule/modulestore/xml.py index 06e824e3d1..e7f9c9ce0a 100644 --- a/common/lib/xmodule/xmodule/modulestore/xml.py +++ b/common/lib/xmodule/xmodule/modulestore/xml.py @@ -1,14 +1,16 @@ import logging +import os +import re + from fs.osfs import OSFS from importlib import import_module from lxml import etree from path import path -from xmodule.errortracker import null_error_tracker +from xmodule.errortracker import ErrorLog, make_error_tracker from xmodule.x_module import XModuleDescriptor, XMLParsingSystem +from xmodule.course_module import CourseDescriptor from xmodule.mako_module import MakoDescriptorSystem from cStringIO import StringIO -import os -import re from . import ModuleStore, Location from .exceptions import ItemNotFoundError @@ -19,7 +21,6 @@ etree.set_default_parser( log = logging.getLogger('mitx.' + __name__) - # VS[compat] # TODO (cpennington): Remove this once all fall 2012 courses have been imported # into the cms from xml @@ -94,14 +95,12 @@ class ImportSystem(XMLParsingSystem, MakoDescriptorSystem): error_tracker, process_xml, **kwargs) - class XMLModuleStore(ModuleStore): """ An XML backed ModuleStore """ def __init__(self, data_dir, default_class=None, eager=False, - course_dirs=None, - error_tracker=null_error_tracker): + course_dirs=None): """ Initialize an XMLModuleStore from data_dir @@ -115,17 +114,14 @@ class XMLModuleStore(ModuleStore): course_dirs: If specified, the list of course_dirs to load. Otherwise, load all course dirs - - error_tracker: The error tracker used here and in the underlying - DescriptorSystem. By default, ignore all messages. - See the comments in x_module.py:DescriptorSystem """ self.eager = eager self.data_dir = path(data_dir) self.modules = {} # location -> XModuleDescriptor self.courses = {} # course_dir -> XModuleDescriptor for the course - self.error_tracker = error_tracker + self.location_errors = {} # location -> ErrorLog + if default_class is None: self.default_class = None @@ -149,15 +145,18 @@ class XMLModuleStore(ModuleStore): for course_dir in course_dirs: try: - course_descriptor = self.load_course(course_dir) + # make a tracker, then stick in the right place once the course loads + # and we know its location + errorlog = make_error_tracker() + course_descriptor = self.load_course(course_dir, errorlog.tracker) self.courses[course_dir] = course_descriptor + self.location_errors[course_descriptor.location] = errorlog except: msg = "Failed to load course '%s'" % course_dir log.exception(msg) - error_tracker(msg) - def load_course(self, course_dir): + def load_course(self, course_dir, tracker): """ Load a course into this module store course_path: Course directory name @@ -191,13 +190,13 @@ class XMLModuleStore(ModuleStore): )) course = course_dir - system = ImportSystem(self, org, course, course_dir, - self.error_tracker) + system = ImportSystem(self, org, course, course_dir, tracker) course_descriptor = system.process_xml(etree.tostring(course_data)) log.debug('========> Done with course import from {0}'.format(course_dir)) return course_descriptor + def get_item(self, location, depth=0): """ Returns an XModuleDescriptor instance for the item at location. @@ -218,9 +217,28 @@ class XMLModuleStore(ModuleStore): except KeyError: raise ItemNotFoundError(location) + + def get_item_errors(self, location): + """ + Return list of errors for this location, if any. Raise the same + errors as get_item if location isn't present. + + NOTE: This only actually works for courses in the xml datastore-- + will return an empty list for all other modules. + """ + location = Location(location) + # check that item is present + self.get_item(location) + + # now look up errors + if location in self.location_errors: + return self.location_errors[location].errors + return [] + def get_courses(self, depth=0): """ - Returns a list of course descriptors + Returns a list of course descriptors. If there were errors on loading, + some of these may be ErrorDescriptors instead. """ return self.courses.values() diff --git a/common/lib/xmodule/xmodule/x_module.py b/common/lib/xmodule/xmodule/x_module.py index a14f83eee6..2a1769bbd7 100644 --- a/common/lib/xmodule/xmodule/x_module.py +++ b/common/lib/xmodule/xmodule/x_module.py @@ -460,8 +460,9 @@ class XModuleDescriptor(Plugin, HTMLSnippet): # Put import here to avoid circular import errors from xmodule.error_module import ErrorDescriptor - - system.error_tracker("Error loading from xml.") + msg = "Error loading from xml." + log.exception(msg) + system.error_tracker(msg) descriptor = ErrorDescriptor.from_xml(xml_data, system, org, course, err) return descriptor diff --git a/lms/djangoapps/courseware/courses.py b/lms/djangoapps/courseware/courses.py index c2c391b08e..cfda6497d5 100644 --- a/lms/djangoapps/courseware/courses.py +++ b/lms/djangoapps/courseware/courses.py @@ -33,6 +33,7 @@ def check_course(course_id, course_must_be_open=True, course_required=True): try: course_loc = CourseDescriptor.id_to_location(course_id) course = modulestore().get_item(course_loc) + except (KeyError, ItemNotFoundError): raise Http404("Course not found.") diff --git a/lms/djangoapps/courseware/views.py b/lms/djangoapps/courseware/views.py index fb4d2942f9..a049638d1b 100644 --- a/lms/djangoapps/courseware/views.py +++ b/lms/djangoapps/courseware/views.py @@ -55,14 +55,20 @@ def user_groups(user): def format_url_params(params): - return [urllib.quote(string.replace(' ', '_')) for string in params] + return [urllib.quote(string.replace(' ', '_')) + if string is not None else None + for string in params] @ensure_csrf_cookie @cache_if_anonymous def courses(request): # TODO: Clean up how 'error' is done. - courses = sorted(modulestore().get_courses(), key=lambda course: course.number) + + # filter out any courses that errored. + courses = [c for c in modulestore().get_courses() + if isinstance(c, CourseDescriptor)] + courses = sorted(courses, key=lambda course: course.number) universities = defaultdict(list) for course in courses: universities[course.org].append(course) @@ -210,7 +216,10 @@ def index(request, course_id, chapter=None, section=None, log.warning("Couldn't find a section descriptor for course_id '{0}'," "chapter '{1}', section '{2}'".format( course_id, chapter, section)) - + else: + if request.user.is_staff: + # Add a list of all the errors... + context['course_errors'] = modulestore().get_item_errors(course.location) result = render_to_response('courseware.html', context) except: diff --git a/lms/templates/courseware.html b/lms/templates/courseware.html index 9c145ba8c0..0955134694 100644 --- a/lms/templates/courseware.html +++ b/lms/templates/courseware.html @@ -47,6 +47,13 @@
${content} + + % if course_errors is not UNDEFINED: +

Course errors

+
+ ${course_errors} +
+ % endif