From 45a808db9523d8ab76590390626b0b01436a576c Mon Sep 17 00:00:00 2001
From: Henrik Levkowetz <henrik@levkowetz.com>
Date: Sat, 24 Oct 2020 15:20:43 +0000
Subject: [PATCH] Added more logging for submissions, to get timing
 information.  - Legacy-Id: 18635

---
 ietf/submit/utils.py | 5 +++++
 ietf/submit/views.py | 3 ++-
 2 files changed, 7 insertions(+), 1 deletion(-)

diff --git a/ietf/submit/utils.py b/ietf/submit/utils.py
index a15deb690..11d265b51 100644
--- a/ietf/submit/utils.py
+++ b/ietf/submit/utils.py
@@ -7,6 +7,7 @@ import io
 import os
 import pathlib
 import re
+import time
 
 from typing import Callable, Optional # pyflakes:ignore
 
@@ -671,6 +672,7 @@ def save_files(form):
         with io.open(name, 'wb+') as destination:
             for chunk in f.chunks():
                 destination.write(chunk)
+        log("saved file %s" % name)
     return file_name
 
 def get_draft_meta(form, saved_files):
@@ -786,6 +788,7 @@ def apply_checkers(submission, file_name):
                                 symbol=checker.symbol)
         check.save()
 
+    mark = time.time()
     for checker_path in settings.IDSUBMIT_CHECKER_CLASSES:
         checker_class = import_string(checker_path)
         checker = checker_class()
@@ -795,6 +798,8 @@ def apply_checkers(submission, file_name):
             if hasattr(checker, method) and ext in file_name:
                 apply_check(submission, checker, method, file_name[ext])
                 break
+    tau = time.time() - mark
+    log("ran submission checks (%.3fs) for %s" % (tau, file_name))
 
 def send_confirmation_emails(request, submission, requires_group_approval, requires_prev_authors_approval):
     docevent_from_submission(request, submission, desc="Uploaded new revision")
diff --git a/ietf/submit/views.py b/ietf/submit/views.py
index 83f6b3283..d54db999a 100644
--- a/ietf/submit/views.py
+++ b/ietf/submit/views.py
@@ -50,6 +50,7 @@ def upload_submission(request):
         try:
             form = SubmissionManualUploadForm(request, data=request.POST, files=request.FILES)
             if form.is_valid():
+                log('got valid submission form for %s' % form.filename)
                 saved_files = save_files(form)
                 authors, abstract, file_name, file_size = get_draft_meta(form, saved_files)
 
@@ -97,7 +98,6 @@ def upload_submission(request):
             form._errors["__all__"] = form.error_class(["There was a failure processing your upload -- please verify that your draft passes idnits.  (%s)" % e.message])
             if debug.debug:
                 raise
-
     else:
         form = SubmissionManualUploadForm(request=request)
 
@@ -119,6 +119,7 @@ def api_submit(request):
         try:
             form = SubmissionAutoUploadForm(request, data=request.POST, files=request.FILES)
             if form.is_valid():
+                log('got valid submission form for %s' % form.filename)
                 username = form.cleaned_data['user']
                 user = User.objects.filter(username=username)
                 if user.count() == 0: