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!

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')

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 = '<p>%s</p>' % msg.replace('<', '&lt;')
                 msg += '<p><pre>%s</pre></p>' % traceback.format_exc().replace('<', '&lt;')
                 # 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'''

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
+

common/lib/xmodule/xmodule/errortracker.py

 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'''

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):

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().

common/lib/xmodule/xmodule/modulestore/xml.py

 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()
 

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

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.")
 

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:

lms/templates/courseware.html

@@ -47,6 +47,13 @@
 
     <section class="course-content">
       ${content}
+
+      % if course_errors is not UNDEFINED:
+          <h2>Course errors</h2>
+          <div id="course-errors">
+            ${course_errors}
+          </div>
+      % endif
     </section>
   </div>
 </section>