Andal.LND/edx-platform
6
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Improved logging for import (#27024)

Browse Source 
* Improved logging for import

* Refactored code

* Refactored code

* Refactored code

* Refactored code

* Refactored code

* refactored code

* Refactored code

* Updating log

Co-authored-by: Awais Jibran <awaisdar001@gmail.com>
This commit is contained in:
AsadAzam
2021-03-18 12:40:38 +05:00
committed by GitHub
parent 3b65406a0d
commit 1593b40702
4 changed files with 44 additions and 36 deletions
Download Patch File Download Diff File Expand all files Collapse all files

2
cms/djangoapps/contentstore/api/views/course_import.py
View File

@@ -150,7 +150,7 @@ class CourseImportView(CourseImportExportViewMixin, GenericAPIView):
'task_id': async_result.task_id
})
except Exception as e:
log.exception(str(e))
log.exception(f'Course import {course_key: Unknown error in import}')
raise self.api_error(
status_code=status.HTTP_500_INTERNAL_SERVER_ERROR,
developer_message=str(e),

35
cms/djangoapps/contentstore/tasks.py
View File

@@ -397,10 +397,12 @@ def import_olx(self, user_id, course_key_string, archive_path, archive_name, lan
user = User.objects.get(pk=user_id)
except User.DoesNotExist:
with translation_language(language):
LOGGER.error(f'Course import {courselike_key}: Unknown User ID: {user_id}')
self.status.fail(_('Unknown User ID: {0}').format(user_id))
return
if not has_course_author_access(user, courselike_key):
with translation_language(language):
LOGGER.error(f'Course import {courselike_key}: Permission denied User ID: {user_id}')
self.status.fail(_('Permission denied'))
return
@@ -422,9 +424,10 @@ def import_olx(self, user_id, course_key_string, archive_path, archive_name, lan
course_dir = data_root / subdir
try:
self.status.set_state('Unpacking')
LOGGER.info(f'Course import {courselike_key}: unpacking step started')
if not archive_name.endswith('.tar.gz'):
with translation_language(language):
LOGGER.error(f'Course import {courselike_key}: Only .tar.gz file is supported')
self.status.fail(_('We only support uploading a .tar.gz file.'))
return
@@ -432,11 +435,11 @@ def import_olx(self, user_id, course_key_string, archive_path, archive_name, lan
if not course_dir.isdir():
os.mkdir(course_dir)
LOGGER.debug(f'importing course to {temp_filepath}')
LOGGER.info(f'Course import: {courselike_key}: importing course to {temp_filepath}')
# Copy the OLX archive from where it was uploaded to (S3, Swift, file system, etc.)
if not course_import_export_storage.exists(archive_path):
LOGGER.info('Course import %s: Uploaded file %s not found', courselike_key, archive_path)
LOGGER.error(f'Course import {courselike_key}: Uploaded file {archive_path} not found')
with translation_language(language):
self.status.fail(_('Tar file not found'))
return
@@ -449,7 +452,7 @@ def import_olx(self, user_id, course_key_string, archive_path, archive_name, lan
return source.read(FILE_READ_CHUNK)
for chunk in iter(read_chunk, b''):
destination.write(chunk)
LOGGER.info('Course import %s: Download from storage complete', courselike_key)
LOGGER.info(f'Course import {courselike_key}: Download from storage complete')
# Delete from source location
course_import_export_storage.delete(archive_path)
@@ -463,16 +466,15 @@ def import_olx(self, user_id, course_key_string, archive_path, archive_name, lan
# TODO: Is this really ok? Seems dangerous for a live course
remove_entrance_exam_milestone_reference(fake_request, courselike_key)
LOGGER.info(
'entrance exam milestone content reference for course %s has been removed',
courselike_module.id
f'Course import {courselike_key}: entrance exam milestone content reference has been removed'
)
# Send errors to client with stage at which error occurred.
except Exception as exception: # pylint: disable=broad-except
if course_dir.isdir():
shutil.rmtree(course_dir)
LOGGER.info('Course import %s: Temp data cleared', courselike_key)
LOGGER.info(f'Course import {courselike_key}: Temp data cleared')
LOGGER.exception('Error importing course %s', courselike_key, exc_info=True)
LOGGER.exception(f'Course import {courselike_key}: Unknown error while unpacking', exc_info=True)
self.status.fail(str(exception))
return
@@ -482,14 +484,14 @@ def import_olx(self, user_id, course_key_string, archive_path, archive_name, lan
try:
safetar_extractall(tar_file, (course_dir + '/'))
except SuspiciousOperation as exc:
LOGGER.info('Course import %s: Unsafe tar file - %s', courselike_key, exc.args[0])
LOGGER.error(f'Course import {courselike_key}: Unsafe tar file')
with translation_language(language):
self.status.fail(_('Unsafe tar file. Aborting import.'))
return
finally:
tar_file.close()
LOGGER.info('Course import %s: Uploaded file extracted', courselike_key)
LOGGER.info(f'Course import {courselike_key}: Uploaded file extracted. Verification step started')
self.status.set_state('Verifying')
self.status.increment_completed_steps()
@@ -517,13 +519,13 @@ def import_olx(self, user_id, course_key_string, archive_path, archive_name, lan
dirpath = get_dir_for_filename(course_dir, root_name)
if not dirpath:
with translation_language(language):
LOGGER.error(f'Course import {courselike_key}: Could not find the {root_name} file in the package.')
self.status.fail(_('Could not find the {0} file in the package.').format(root_name))
return
dirpath = os.path.relpath(dirpath, data_root)
LOGGER.debug('found %s at %s', root_name, dirpath)
LOGGER.info('Course import %s: Extracted file verified', courselike_key)
LOGGER.info(f'Course import {courselike_key}: Extracted file verified. Updating course started')
self.status.set_state('Updating')
self.status.increment_completed_steps()
@@ -532,20 +534,21 @@ def import_olx(self, user_id, course_key_string, archive_path, archive_name, lan
settings.GITHUB_REPO_ROOT, [dirpath],
load_error_modules=False,
static_content_store=contentstore(),
target_id=courselike_key
target_id=courselike_key,
verbose=True
)
new_location = courselike_items[0].location
LOGGER.debug('new course at %s', new_location)
LOGGER.info('Course import %s: Course import successful', courselike_key)
LOGGER.info(f'Course import {courselike_key}: Course import successful')
except Exception as exception: # pylint: disable=broad-except
LOGGER.exception('error importing course', exc_info=True)
LOGGER.exception(f'Course import {courselike_key}: Unknown error while updating course')
self.status.fail(str(exception))
finally:
if course_dir.isdir():
shutil.rmtree(course_dir)
LOGGER.info('Course import %s: Temp data cleared', courselike_key)
LOGGER.info(f'Course import {courselike_key}: Temp data cleared')
if self.status.state == 'Updating' and is_course:
# Reload the course so we have the latest state

15
cms/djangoapps/contentstore/views/import_export.py
View File

@@ -142,7 +142,7 @@ def _write_chunk(request, courselike_key):
if not course_dir.isdir():
os.mkdir(course_dir)
logging.debug(f'importing course to {temp_filepath}')
logging.info(f'Course import {courselike_key}: importing course to {temp_filepath}')
# Get upload chunks byte ranges
try:
@@ -150,6 +150,7 @@ def _write_chunk(request, courselike_key):
content_range = matches.groupdict()
except KeyError: # Single chunk
# no Content-Range header, so make one that will work
logging.info(f'Course import {courselike_key}: single chunk found')
content_range = {'start': 0, 'stop': 1, 'end': 2}
# stream out the uploaded files in chunks to disk
@@ -163,10 +164,8 @@ def _write_chunk(request, courselike_key):
# the same session, but it's always better to catch errors earlier.
if size < int(content_range['start']):
_save_request_status(request, courselike_string, -1)
log.warning(
"Reported range %s does not match size downloaded so far %s",
content_range['start'],
size
log.error(
f'Course import {courselike_key}: A chunk has been missed'
)
return JsonResponse(
{
@@ -199,7 +198,7 @@ def _write_chunk(request, courselike_key):
}]
})
log.info("Course import %s: Upload complete", courselike_key)
log.info(f'Course import {courselike_key}: Upload complete')
with open(temp_filepath, 'rb') as local_file:
django_file = File(local_file)
storage_path = course_import_export_storage.save('olx_import/' + filename, django_file)
@@ -213,9 +212,7 @@ def _write_chunk(request, courselike_key):
shutil.rmtree(course_dir)
log.info("Course import %s: Temp data cleared", courselike_key)
log.exception(
"error importing course"
)
log.exception(f'Course import {courselike_key}: error importing course.')
return JsonResponse(
{
'ErrMsg': str(exception),

28
common/lib/xmodule/xmodule/modulestore/xml_importer.py
View File

@@ -173,7 +173,7 @@ class StaticContentImporter: # lint-amnesty, pylint: disable=missing-class-docs
try:
self.static_content_store.save(content)
except Exception as err: # lint-amnesty, pylint: disable=broad-except
msg = f"Error importing {file_subpath}, error={err}"
msg = f"Course import {self.target_id}: Error importing {file_subpath}, error={err}"
log.exception(msg)
set_custom_attribute('course_import_failure', f"Static Content Save Failure: {msg}")
@@ -274,7 +274,9 @@ class ImportManager:
Import all static items into the content store.
"""
if self.static_content_store is None:
log.warning("Static content store is None. Skipping static content import...")
log.error(
f'Course import {self.target_id}: Static content store is None. Skipping static content import.'
)
return
static_content_importer = StaticContentImporter(
@@ -284,14 +286,16 @@ class ImportManager:
)
if self.do_import_static:
if self.verbose:
log.debug("Importing static content and python library")
log.info(f'Course import {self.target_id}: Importing static content and python library')
# first pass to find everything in the static content directory
static_content_importer.import_static_content_directory(
content_subdir=self.static_content_subdir, verbose=self.verbose
)
elif self.do_import_python_lib and self.python_lib_filename:
if self.verbose:
log.debug("Skipping static content import, still importing python library")
log.info(
f'Course import {self.target_id}: Skipping static content import, still importing python library'
)
python_lib_dir_path = data_path / self.static_content_subdir
python_lib_full_path = python_lib_dir_path / self.python_lib_filename
if os.path.isfile(python_lib_full_path):
@@ -300,7 +304,7 @@ class ImportManager:
)
else:
if self.verbose:
log.debug("Skipping import of static content and python library")
log.info(f'Course import {self.target_id}: Skipping import of static content and python library')
# No matter what do_import_static is, import "static_import" directory.
# This is needed because the "about" pages (eg "overview") are
@@ -314,7 +318,7 @@ class ImportManager:
simport = 'static_import'
if os.path.exists(data_path / simport):
if self.verbose:
log.debug("Importing %s directory", simport)
log.info(f'Course import {self.target_id}: Importing {simport} directory')
static_content_importer.import_static_content_directory(
content_subdir=simport, verbose=self.verbose
)
@@ -352,10 +356,12 @@ class ImportManager:
asset_md.from_xml(asset)
all_assets.append(asset_md)
except OSError:
logging.info('No %s file is present with asset metadata.', assets_filename)
logging.error(
f'Course import {self.target_id}: No {assets_filename} file is present with asset metadata.'
)
return
except Exception: # pylint: disable=W0703
logging.exception('Error while parsing asset xml.')
logging.exception(f'Course import {self.target_id}: Error while parsing asset xml.')
if self.raise_on_failure: # lint-amnesty, pylint: disable=no-else-raise
raise
else:
@@ -471,7 +477,9 @@ class ImportManager:
runtime=courselike.runtime,
)
except Exception:
log.error('failed to import module location %s', child.location)
log.exception(
f'Course import {self.target_id}: failed to import module location {child.location}'
)
raise
depth_first(child)
@@ -493,7 +501,7 @@ class ImportManager:
runtime=courselike.runtime,
)
except Exception:
msg = f'failed to import module location {leftover}'
msg = f'Course import {self.target_id}: failed to import module location {leftover}'
log.error(msg)
set_custom_attribute('course_import_failure', f"Module Load failure: {msg}")
raise