Merge pull request #316 from wlach/ingestion-logging

Bug 1118484 - Add additional logging for pushlog/log ingestion

treeherder/etl/pushlog.py

@@ -82,6 +82,9 @@ class HgPushlogProcess(HgPushlogTransformerMixin,
         # reduce the number of pushes processed every time
         last_push = cache.get("{0}:last_push".format(repository))
         if not changeset and last_push:
+            logger.info("Extracted last push for '%s', '%s', from cache, "
+                        "attempting to get changes only from that point" %
+                        (repository, last_push))
             try:
                 # make an attempt to use the last revision cached
                 extracted_content = self.extract(
@@ -91,15 +94,22 @@ class HgPushlogProcess(HgPushlogTransformerMixin,
                 # in case of a 404 error, delete the cache key
                 # and try it without any parameter
                 if e.response.status_code == 404:
+                    logger.warning("Got a 404 fetching changes since '%s', "
+                                   "getting all changes for '%s' instead" %
+                                   (last_push, repository))
                     cache.delete("{0}:last_push".format(repository))
                     extracted_content = self.extract(source_url)
                 else:
                     raise e
         else:
             if changeset:
+                logger.info("Getting all pushes for '%s' corresponding to "
+                            "changeset '%s'" % (repository, changeset))
                 extracted_content = self.extract(source_url + "&changeset=" +
                                                  changeset)
             else:
+                logger.warning("Unable to get last push from cache for '%s', "
+                               "getting all pushes" % repository)
                 extracted_content = self.extract(source_url)
 
         if extracted_content:

treeherder/log_parser/tasks.py

@@ -3,6 +3,7 @@
 # file, you can obtain one at http://mozilla.org/MPL/2.0/.
 
 
+import logging
 import time
 from celery import task
 from django.conf import settings
@@ -19,6 +20,8 @@ from treeherder.log_parser.utils import (get_error_search_term,
 from treeherder.etl.oauth_utils import OAuthCredentials
 
 
+logger = logging.getLogger(__name__)
+
 @task(name='parse-log', max_retries=10)
 def parse_log(project, job_log_url, job_guid, check_errors=False):
     """
@@ -44,6 +47,9 @@ def parse_log(project, job_log_url, job_guid, check_errors=False):
             job_log_url['id']
         )
 
+        logger.debug("Downloading and extracting log information for guid "
+                     "'%s' (from %s)" % (job_guid, job_log_url['url']))
+
         artifact_list = extract_log_artifacts(job_log_url['url'],
                                               job_guid, check_errors)
         # store the artifacts generated
@@ -57,6 +63,9 @@ def parse_log(project, job_log_url, job_guid, check_errors=False):
             })
             tac.add(ta)
 
+        logger.debug("Finished downloading and processing artifact for guid "
+                     "'%s'" % job_guid)
+
         req.post(tac)
 
         # send an update to job_log_url
@@ -70,9 +79,14 @@ def parse_log(project, job_log_url, job_guid, check_errors=False):
                 'parse_timestamp': current_timestamp
             }
         )
+
+        logger.debug("Finished posting artifact for guid '%s'" % job_guid)
+
     except Exception, e:
         # send an update to job_log_url
         #the job_log_url status changes from pending/running to failed
+        logger.warn("Failed to download and/or parse artifact for guid '%s'" %
+                    job_guid)
         current_timestamp = time.time()
         req.send(
             update_endpoint,