Issue 395 - Filter hits statistics backend

sitescripts/filterhits/web/submit.py

 # coding: utf-8
 
 # This file is part of the Adblock Plus web scripts,
 # Copyright (C) 2006-2015 Eyeo GmbH
 #
 # Adblock Plus is free software: you can redistribute it and/or modify
 # it under the terms of the GNU General Public License version 3 as
 # published by the Free Software Foundation.
 #
 # Adblock Plus is distributed in the hope that it will be useful,
 # but WITHOUT ANY WARRANTY; without even the implied warranty of
 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 # GNU General Public License for more details.
 #
 # You should have received a copy of the GNU General Public License
 # along with Adblock Plus.  If not, see <http://www.gnu.org/licenses/>.
 
 import json
-import MySQLdb
+import os
 import tempfile
 import time
-import os
+import traceback
 from datetime import datetime
 from errno import EEXIST
 
+import MySQLdb
+
 from sitescripts.web import url_handler
 from sitescripts.utils import get_config, setupStderr
-from sitescripts.filterhits import common, db, geometrical_mean
+from sitescripts.filterhits import db, geometrical_mean
+from sitescripts.filterhits.web import common
 
 def log_filterhits(data, basepath, query_string):
   """
   This logs the provided filterhits data as JSON to a file named after
   the current timestamp in a directory named after the current date.
   """
   now = time.gmtime()
 
   dir_name = time.strftime("%Y-%m-%d", now)
   path = os.path.join(basepath, dir_name)
   try:
     os.makedirs(path)
   except OSError as e:
     if e.errno != EEXIST:
       raise
 
   with tempfile.NamedTemporaryFile(
     prefix = str(int(time.mktime(now))) + "-",
     suffix = ".log",
     dir = path,
     delete = False
   ) as f:
-    print >> f, "[%s] \"%s\"" % (time.strftime('%d/%b/%Y:%H:%M:%S', now),
-                                 query_string)

[Wladimir Palant, 2015/03/27 16:29:06]

I wonder whether quotation marks in the query string will break any of the tools
you wrote. And before you object that most browsers will turn quotation marks
into %22 - sure, but anybody using telnet or an older IE version can still send
them to the server.

Given that a query string cannot have whitespace in it due to specifics of the
HTTP protocol - why use quotation marks as delimiters here?

[kzar, 2015/03/27 22:15:00]

(Give me a little credit, I would not assume data sent from the client is safe /
correct.)

Done.

-    print >> f, json.dumps(data)

[Sebastian Noack, 2015/03/27 16:31:04]

json.dump(data, f)

[kzar, 2015/03/27 22:15:00]

Done.

+    print >> f, "[%s] %s" % (time.strftime("%d/%b/%Y:%H:%M:%S", now), query_string)
+    json.dump(data, f)
     return f.name
 
 @url_handler("/submit")
 def submit(environ, start_response):
   setupStderr(environ["wsgi.errors"])
   config = get_config()
 
   # Check that this is a POST request
   if environ["REQUEST_METHOD"] != "POST":
     return common.show_error("Unsupported request method", start_response)
 
   # Parse the submitted JSON
   try:
     data = json.loads(environ["wsgi.input"].read(int(environ["CONTENT_LENGTH"])))
   except (KeyError, IOError, ValueError):
     return common.show_error("Error while parsing JSON data.", start_response)
 
   # Make sure the submitted data was contained within an object at least
   if not isinstance(data, dict):
     return common.show_error("Error, data must be contained within an object.", start_response)
 
   # Log the data to a file
-  if not db.testing:
-    log_dir = config.get("filterhitstats", "log_dir")
-    try:
-      log_file = log_filterhits(data, log_dir, environ.get("QUERY_STRING", ""))
-    except (OSError, IOError):
-      return common.show_error("Failed to write data to log file!", start_response,
-                              "500 Logging error")

[Wladimir Palant, 2015/03/27 16:29:06]

This seems to be an unexpected error, one that is worth logging. Do
traceback.print_exc() as well here?

[kzar, 2015/03/27 22:15:00]

Done.

+  log_dir = config.get("filterhitstats", "log_dir")
+  try:
+    log_file = log_filterhits(data, log_dir, environ.get("QUERY_STRING", ""))
+  except (OSError, IOError):
+    traceback.print_exc()
+    return common.show_error("Failed to write data to log file!", start_response,
+                             "500 Logging error")
 
   # Update the geometrical_mean aggregations in the database
   interval = config.get("filterhitstats", "interval")
   try:
     db_connection = db.connect()
     try:
       db.write(db_connection, geometrical_mean.update(interval, data))
     finally:
       db_connection.close()
-  except (KeyError, MySQLdb.Error), e:
+  except:
     # Updating the aggregations in the database failed for whatever reason,
-    # log the details but continue to return 200 OK to the client to avoid
-    # re-transmission of the data.
-    if not db.testing:
-      processing_error_log = os.path.join(config.get("filterhitstats", "log_dir"),
-                                     "processing-errors.log")
-      with open(processing_error_log, "a+") as f:
-        if isinstance(e, KeyError):
-          message = "KeyError (%s) when processing data file %s" % (str(e.args[0]), log_file)
-        elif isinstance(e, MySQLdb.Error):
-          message = "MySQL error (%d) when processing data file %s: \"%s\"" % (e.args[0], log_file, e.args[1])
-        print >> f, "[%s] %s" % (datetime.now().strftime('%d/%b/%Y:%H:%M:%S %z'), message)

[Wladimir Palant, 2015/03/27 16:29:06]

I'd suggest using traceback module here instead of generating custom messages.
This should also allow logging any error types rather than only two.

[kzar, 2015/03/27 22:15:00]

Done.

+    # log the details but continue to return 204 to the client to avoid the
+    # re-transmission of data.
+    processing_error_log = os.path.join(config.get("filterhitstats", "log_dir"),
+                                        "processing-errors.log")
+    with open(processing_error_log, "a+") as f:
+      message = "Problem processing data file %s:\n%s" % (
+        log_file, traceback.format_exc()
+      )
+      print >> f, "[%s] %s" % (datetime.now().strftime("%d/%b/%Y:%H:%M:%S %z"), message)
 
-  # Send back a 200 OK response
-  response_headers = [("Content-type", "text/plain")]
-  start_response("200 OK", response_headers)
+  # Send back a 204 No Content
+  start_response("204 No Content", [])
   return []