Extensive logging for the REST layer

portal/async_celery/tasks.py

@@ -14,6 +14,7 @@ def process_submission(new_submission_id: str):
     new_submission = rest_service.find.submission(new_submission_id)
     project = new_submission.project
     course = project.course
+    log.info(f"[SUBMIT] Processing submission: {new_submission.log_name}")
     if not project.config.test_files_commit_hash:
         log.warning(f"Project test files not found: {project.log_name}")
         update_project_test_files(course_id=course.id, project_id=project.id)
@@ -28,6 +29,8 @@ def upload_results_to_storage(new_submission_id: str, path: str):
     from portal.service.rest import RestService
     rest_service = RestService()
     new_submission = rest_service.find.submission(new_submission_id)
+    log.info(f"[SUBMIT] Processing results - upload to the storage for "
+             f"{new_submission.log_name}: {path}")
     processor = submission_processor.SubmissionProcessor(new_submission)
     file_params = dict(source=dict(url=path, type='zip'))
     processor.upload_result(path=path, file_params=file_params)
@@ -41,6 +44,7 @@ def clone_submission_files(source_id: str, target_id: str):
     rest_service = RestService()
     source = rest_service.find.submission(source_id)
     target = rest_service.find.submission(target_id)
+    log.info(f"[SUBMIT] Copy submission files: {source.log_name} -> {target.log_name}")
     processor = submission_processor.SubmissionProcessor(source)
     processor.clone(target)
 
@@ -49,8 +53,8 @@ def clone_submission_files(source_id: str, target_id: str):
 def start_processing_submission(submission_id: str, submission_params):
     from portal.service.rest import RestService
     rest_service = RestService()
-
     submission = rest_service.find.submission(submission_id)
+    log.info(f"[SUBMIT] Processing submission - send to worker: {submission.log_name}")
     processor = submission_processor.SubmissionProcessor(submission, submission_params)
     processor.send_to_worker()
 

portal/rest/courses.py

@@ -33,8 +33,8 @@ class CourseList(CustomResource):
     @access_log
     def post(self):
         self.permissions.require.sysadmin()
-
         data = rest_helpers.parse_request_data(resource='course', action='create')
+        log.info(f"[REST] Create new course by {self.client.log_name}: {data} ")
         new_course = self.rest.courses.create(**data)
         return SCHEMAS.dump('course', new_course), 201
 
@@ -70,6 +70,7 @@ class CourseResource(CustomResource):
     def delete(self, cid: str):
         self.permissions.require.sysadmin()
         course = self.rest.find.course(cid)
+        log.info(f"[REST] Delete course {course.log_name} by {self.client.log_name}")
         self.rest.courses(course).delete()
         return '', 204
 
@@ -81,8 +82,8 @@ class CourseResource(CustomResource):
         course = self.rest.find.course(cid)
         # authorization
         self.permissions(course=course).require.update_course()
-
         data = rest_helpers.parse_request_data(action='update', resource='course', partial=True)
+        log.info(f"[REST] Update course by {self.client.log_name}: {data} ")
         self.rest.courses(course).update(**data)
         return '', 204
 
@@ -112,7 +113,7 @@ class CourseNotesToken(CustomResource):
         self.permissions(course=course).require.course_access_token()
 
         json_data = rest_helpers.require_data(action='update_notes_token', resource='course')
-
+        log.info(f"[REST] Update course access token by {self.client.log_name}: {json_data} ")
         self.rest.courses(course).update_notes_token(json_data['token'])
         return '', 204
 
@@ -140,6 +141,8 @@ class CourseImport(CustomResource):
                 400, f'[IMPORT] Cannot import course to itself. (id: {cid})')
 
         config = data['config']
+        log.info(f"[REST] Import course by {self.client.log_name} "
+                 f"from {source_course}: {config} ")
 
         copied_course = self.rest.courses(course).copy_course(course, config)
         return SCHEMAS.dump('course', copied_course)

portal/rest/custom_resource.py

@@ -19,3 +19,7 @@ class CustomResource(Resource):
     @property
     def permissions(self) -> PermissionsService:
         return self.rest.permissions
+
+    @property
+    def client(self):
+        return self.rest.auth.client

portal/rest/gitlab.py

@@ -98,7 +98,7 @@ def user_oauth_register(user_info):
         email=user_info['email'],
         is_admin=False
     )
-    log.debug(f"[GITLAB] Created user={new_user}")
+    log.info(f"[GITLAB] Created user={new_user}")
     return new_user
 
 

portal/rest/groups.py

@@ -34,7 +34,7 @@ class GroupsList(CustomResource):
         self.permissions(course=course).require.update_course()
 
         data = rest_helpers.parse_request_data(action='create', resource='group')
-
+        log.info(f"[REST] Create new group by {self.client.log_name} in {course.log_name}: {data}")
         new_group = self.rest.groups.create(course, **data)
         return SCHEMAS.dump('group', new_group), 201
 
@@ -64,8 +64,8 @@ class GroupResource(CustomResource):
         course = self.find.course(cid)
         # authorization
         self.permissions(course=course).require.update_course()
-
         group = self.find.group(course, gid)
+        log.info(f"[REST] Delete group {group.log_name} by {self.client.log_name}")
         self.rest.groups(group).delete()
         return '', 204
 
@@ -77,9 +77,9 @@ class GroupResource(CustomResource):
         course = self.find.course(cid)
         # authorization
         self.permissions(course=course).require.write_groups()
-
         data = rest_helpers.parse_request_data(action='update', resource='group', partial=True)
         group = self.find.group(course, gid)
+        log.info(f"[REST] Update group {group.log_name} by {self.client.log_name}: {data}")
         self.rest.groups(group).update(**data)
         return '', 204
 
@@ -116,6 +116,8 @@ class GroupUsersList(CustomResource):
         )
 
         group = self.find.group(course, gid)
+        log.info(f"[REST] Update group membership {group.log_name} by "
+                 f"{self.client.log_name}: {data}")
         # everything from users_add is added, THEN everything from users_remove
         # is removed
         self.rest.groups(group).update_membership(data)
@@ -144,6 +146,8 @@ class GroupAddOrDeleteSingleUser(CustomResource):
         group = self.find.group(course, gid)
         user = self.find.user(uid)
         self.rest.groups(group).add_user(user)
+        log.info(f"[REST] Update group membership {group.log_name} by "
+                 f"{self.client.log_name}, add user {user.log_name}")
         return '', 204
 
     @jwt_required
@@ -158,6 +162,8 @@ class GroupAddOrDeleteSingleUser(CustomResource):
         group = self.find.group(course, gid)
         user = self.find.user(uid)
         self.rest.groups(group).remove_user(user)
+        log.info(f"[REST] Update group membership {group.log_name} by "
+                 f"{self.client.log_name}, remove user {user.log_name}")
         return '', 204
 
 
@@ -200,6 +206,8 @@ class GroupAddOrDeleteProject(CustomResource):
         group = self.find.group(course, gid)
         project = self.find.project(course, pid)
         self.rest.groups(group).add_project(project)
+        log.info(f"[REST] Update group membership {group.log_name} by "
+                 f"{self.client.log_name}, add project {project.log_name}")
         return '', 204
 
     @jwt_required
@@ -216,6 +224,8 @@ class GroupAddOrDeleteProject(CustomResource):
         group = self.find.group(course, gid)
         project = self.find.project(course, pid)
         self.rest.groups(group).remove_project(project)
+        log.info(f"[REST] Update group membership {group.log_name} by "
+                 f"{self.client.log_name}, remove project {project.log_name}")
         return '', 204
 
 
@@ -235,5 +245,6 @@ class GroupImport(CustomResource):
         data = rest_helpers.parse_request_data(
             schema=SCHEMAS.group_import, action='import', resource='group'
         )
+        log.info(f"[REST] Group import by {self.client.log_name}: {data}")
         new_group = self.rest.groups.import_group(data, target_course)
         return SCHEMAS.dump('group', new_group), 201

portal/rest/projects.py

@@ -37,7 +37,8 @@ class ProjectsList(CustomResource):
         self.permissions(course=course).require.update_course()
 
         data = rest_helpers.parse_request_data(action='create', resource='project')
-
+        log.info(f"[REST] Create new project by {self.client.log_name} "
+                 f"in {course.log_name}: {data}")
         new_project = self.rest.projects.create(course, **data)
         return SCHEMAS.dump('project', new_project), 201
 
@@ -67,8 +68,8 @@ class ProjectResource(CustomResource):
         course = self.find.course(cid)
         # authorization
         self.permissions(course=course).require.update_course()
-
         project = self.find.project(course, pid)
+        log.info(f"[REST] Delete project by {self.client.log_name}: {project.log_name}")
         self.rest.projects(project).delete()
         return '', 204
 
@@ -82,8 +83,8 @@ class ProjectResource(CustomResource):
         self.permissions(course=course).require.write_projects()
 
         data = rest_helpers.parse_request_data(action='update', resource='project', partial=True)
-
         project = self.find.project(course, pid)
+        log.info(f"[REST] Update project {project.log_name} by {self.client.log_name}: {data}")
         self.rest.projects(project).update(**data)
         return '', 204
 
@@ -123,6 +124,8 @@ class ProjectConfigResource(CustomResource):
 
         data = rest_helpers.parse_request_data(action='update', resource='config')
         project = self.find.project(course, pid)
+        log.info(f"[REST] Update project config in "
+                 f"{project.log_name} by {self.client.log_name}: {data}")
         self.rest.projects(project).update_project_config(data)
         return '', 204
 
@@ -141,6 +144,8 @@ class ProjectTestFilesRefresh(CustomResource):
         project = self.find.project(course, pid)
         # authorization
         self.permissions(course=course).require.write_projects()
+        log.info(f"[REST] Update project test-files for "
+                 f"{project.log_name} by {self.client.log_name}")
         self.rest.projects(project).update_project_test_files()
         return '', 204
 
@@ -186,11 +191,12 @@ class ProjectSubmissions(CustomResource):
         data = rest_helpers.parse_request_data(
             schema=SCHEMAS.submission_create, action='create', resource='submission'
         )
-        log.debug(f"[REST] Create submission: {data}")
+        log.info(f"[REST] Create submission in {project.log_name} "
+                 f"by {self.client.log_name} for user {user.log_name}: {data}")
 
         # data for Kontr processing
         service = self.rest.submissions()
-        new_submission = service.create(user=user,project=project,submission_params=data)
+        new_submission = service.create(user=user, project=project, submission_params=data)
         return SCHEMAS.dump('submission', new_submission), 201
 
 

portal/rest/roles.py

@@ -33,6 +33,8 @@ class RoleList(CustomResource):
         self.permissions(course=course).require.update_course()
 
         data = rest_helpers.parse_request_data(action='create', resource='role')
+        log.info(f"[REST] Create new role for {course.log_name} "
+                 f"by {self.client.log_name}: {data}")
         new_role = self.rest.roles.create(course, **data)
         return SCHEMAS.dump('role', new_role), 201
 
@@ -62,6 +64,7 @@ class RoleResource(CustomResource):
         self.permissions(course=course).require.update_course()
 
         role = self.find.role(course, rid)
+        log.info(f"[REST] Delete role {role.log_name} by {self.client.log_name}")
         self.rest.roles(role).delete()
         return '', 204
 
@@ -76,6 +79,7 @@ class RoleResource(CustomResource):
         data = rest_helpers.parse_request_data(action='update', resource='role', partial=True)
 
         role = self.find.role(course, rid)
+        log.info(f"[REST] Update role {role.log_name} by {self.client.log_name}: {data}")
         self.rest.roles(role).update(**data)
         return '', 204
 
@@ -106,8 +110,9 @@ class RolePermissions(CustomResource):
         self.permissions(course=course).require.write_roles()
 
         data = rest_helpers.parse_request_data(action='update', resource='permissions')
-
         role = self.find.role(course, rid)
+        log.info(f"[REST] Update role permissions for"
+                 f" {role.log_name} by {self.client.log_name}: {data}")
         self.rest.roles(role).update_permissions(data)
         return SCHEMAS.dump('permissions', role.permissions), 200
 
@@ -146,6 +151,8 @@ class RoleUsersList(CustomResource):
         # everything from users_add is added, THEN everything from users_remove
         # is subtracted
         role = self.find.role(course, rid)
+        log.info(f"[REST] Update role membership for"
+                 f" {role.log_name} by {self.client.log_name}: {data}")
         self.rest.roles(role).update_clients_membership(data)
         return '', 204
 
@@ -170,6 +177,8 @@ class RoleClient(CustomResource):
         client_type = request.args.get('type')
         client = self.find.client(clid, client_type=client_type)
         self.rest.roles(role).add_client(client)
+        log.info(f"[REST] Update role membership for"
+                 f" {role.log_name} by {self.client.log_name} - add client: {client.log_name}")
         return '', 204
 
     @jwt_required
@@ -182,4 +191,6 @@ class RoleClient(CustomResource):
         client_type = request.args.get('type')
         client = self.find.client(clid, client_type=client_type)
         self.rest.roles(role).remove_client(client)
+        log.info(f"[REST] Update role membership for"
+                 f" {role.log_name} by {self.client.log_name} - add remove: {client.log_name}")
         return '', 204

portal/rest/submissions.py

@@ -39,6 +39,7 @@ class SubmissionResource(CustomResource):
     def delete(self, sid: str):
         self.permissions.require.sysadmin()
         submission = self.find.submission(sid)
+        log.info(f"[REST] Delete submission by {self.client.log_name}: {submission.log_name}")
         self.rest.submissions(submission).delete()
         return '', 204
 
@@ -65,6 +66,8 @@ class SubmissionState(CustomResource):
         data = rest_helpers.parse_request_data(action='update_state', resource='submission_state')
         service = self.rest.submissions(submission)
         service.update_submission_state(client=client, data=data)
+        log.info(f"[REST] Update submission state for {submission.log_name}  by "
+                 f"{self.client.log_name}: {data}")
         return '', 204
 
 
@@ -181,6 +184,8 @@ class SubmissionResultFiles(CustomResource):
         # todo: authorize worker
         service = self.rest.submissions(submission)
         task = service.upload_results_to_storage()
+        log.info(f"[REST] Upload submission results for {submission.log_name} by "
+                 f"{self.client.log_name}")
         return {'new_task': task.id}
 
 
@@ -203,6 +208,8 @@ class SubmissionResubmit(CustomResource):
         # storage
         service = self.rest.submissions(source_submission)
         new_submission = service.copy_submission(note=data['note'])
+        log.info(f"[REST] Resubmit submission {source_submission.log_name} by "
+                 f"{self.client.log_name}: {data}")
         return SCHEMAS.dump('submission', new_submission), 201
 
 
@@ -224,6 +231,8 @@ class SubmissionCancel(CustomResource):
         # storage
         service = self.rest.submissions(submission)
         service.cancel_submission()
+        log.info(f"[REST] Cancel submission {submission.log_name} by "
+                 f"{self.client.log_name}")
         return '', 204
 
 
@@ -256,5 +265,6 @@ class SubmissionReview(CustomResource):
 
         # also writes to db
         review_service.create_review_items(items=data['review_items'], author=client)
-
+        log.info(f"[REST] Create submission review {submission.log_name} by "
+                 f"{self.client.log_name}: {data}")
         return SCHEMAS.dump('review', submission.review), 201

portal/rest/users.py

@@ -44,6 +44,7 @@ class UserList(CustomResource):
         self.permissions().require.sysadmin()
         data = rest_helpers.parse_request_data(action='create', resource='user')
         new_user = self.rest.users.create(**data)
+        log.info(f"[REST] Create new user by {self.client.log_name}: {data}")
         return SCHEMAS.dump('user', new_user), 201
 
 
@@ -74,6 +75,7 @@ class UserResource(CustomResource):
         permissions_service.require.sysadmin_or_self(uid)
 
         data = rest_helpers.parse_request_data(action='update', resource='user', partial=True)
+        log.info(f"[REST] Update user {user.log_name} by {self.client.log_name}: {data}")
         self.rest.users(user).update(**data)
         return '', 204
 
@@ -83,6 +85,7 @@ class UserResource(CustomResource):
     def delete(self, uid: str):
         self.permissions().require.sysadmin()
         user = self.find.user(uid)
+        log.info(f"[REST] Delete user {user.log_name} by {self.client.log_name}")
         self.rest.users(user).delete()
         return '', 204
 
@@ -98,6 +101,7 @@ class UserPassword(CustomResource):
         user = self.find.user(uid)
         self.permissions().require.sysadmin_or_self(uid)
         data = rest_helpers.parse_request_data(action='update', resource='password_change')
+        log.info(f"[REST] Update user password {user.log_name} by {self.client.log_name}")
         self.rest.users(user).update_password(data)
         return '', 204
 

portal/rest/workers.py

@@ -28,6 +28,7 @@ class WorkerList(CustomResource):
     def post(self):
         self.permissions().require.sysadmin()
         data = rest_helpers.parse_request_data(action='create', resource='worker')
+        log.info(f"[REST] Create new worker by {self.client.log_name}: {data}")
         new_worker = self.rest.workers.create(**data)
         return SCHEMAS.dump('worker', new_worker), 201
 
@@ -52,6 +53,7 @@ class WorkerResource(CustomResource):
     def delete(self, wid: str):
         self.permissions().require.sysadmin()
         worker = self.find.worker(wid)
+        log.info(f"[REST] Delete worker {worker.log_name} by {self.client.log_name}")
         self.rest.workers(worker).delete()
         return '', 204
 
@@ -63,6 +65,7 @@ class WorkerResource(CustomResource):
         self.permissions().require.sysadmin_or_self(wid)
         data = rest_helpers.parse_request_data(action='update', resource='worker', partial=True)
         worker = self.find.worker(wid)
+        log.info(f"[REST] Update worker {worker.log_name} by {self.client.log_name}: {data}")
         self.rest.workers(worker).update(**data)
         return '', 204
 

portal/service/submissions.py

@@ -69,6 +69,9 @@ class SubmissionsService(GeneralService):
           """
         # adding review at submission create is not supported
         submission_params = self.process_submission_params(submission_params, project, user=user)
+        log.info(f"[SUBMIT] Create new submission for user {user.log_name} "
+                 f"by {self.client.log_name} for project {project.log_name} "
+                 f"with params: {submission_params}")
         new_submission = Submission(
             user=user, project=project, parameters=submission_params)
         self.write_entity(new_submission)
@@ -96,13 +99,13 @@ class SubmissionsService(GeneralService):
 
     def process_new_submission(self) -> AsyncResult:
         project = self.submission.project
-
         self.submission.parameters['file_params'] = project.config.file_whitelist
         self.write_entity(self.submission)
         task = self.create_process_submission_task()
         return task
 
     def create_process_submission_task(self) -> AsyncResult:
+        log.info(f"[SUBMIT] Processing task for {self.submission.log_name}")
         result: AsyncResult = tasks.process_submission.delay(self.submission.id)
         self.submission.storage_task_id = result.task_id
         return result