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-2014 Eyeo GmbH
+# 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 MySQLdb, json, os
+import json
+import os
+import tempfile
+import time
+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 db, geometrical_mean
+from sitescripts.filterhits.web import common
 
-import sitescripts.filterhits.common as common
-import sitescripts.filterhits.db as db
-import sitescripts.filterhits.geometrical_mean as geometrical_mean
+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)
+    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"].upper() != "POST":

[Sebastian Noack, 2015/02/11 16:00:12]

According to the specs REQUEST_METHOD is always already uppercase:
http://wsgi.readthedocs.org/en/latest/definitions.html

[kzar, 2015/02/17 10:52:24]

Done.

-    return common.showError("Unsupported request method", start_response)
+  if environ["REQUEST_METHOD"] != "POST":
+    return common.show_error("Unsupported request method", start_response)
 
   # Parse the submitted JSON
-  data = "{}"
   try:
-    data_length = int(environ.get("CONTENT_LENGTH", "0"))
-  except ValueError:

[Sebastian Noack, 2015/02/11 16:00:12]

If you just catch the KeyError as well you can use canonical key lookups, and
don't need to specify the fallback twice: 

try:
  data_length = int(environ["CONTENT_LENGTH"])
except (ValueError, KeyError):
  data_length = 0

[kzar, 2015/02/17 10:52:24]

Done.

-    data_length = 0
-  if data_length != 0:
-    data = environ["wsgi.input"].read(data_length)
-  try:
-    data = json.loads(data)
-  except json.decoder.JSONDecodeError:
-    return common.showError("Error while parsing JSON data.", start_response)
+    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 it looks roughly valid
-  if not common.valid_log_data(data):
-    return common.showError("Data looks invalid.", 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
   log_dir = config.get("filterhitstats", "log_dir")
   try:
-    log_file = common.log_filterhits(data, log_dir,
-                                     environ.get("QUERY_STRING", ""))
-  except OSError, IOError:

[Sebastian Noack, 2015/02/11 16:00:12]

You need parentheses here. Otherwise - as it currently is - the catched OSError
will be stored in the variable IOError, while IOErrors are not handled.

[kzar, 2015/02/17 10:52:24]

Done.

-    return common.showError("Failed to write data to log file!", start_response,
-                            "500 Logging error")
+    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.connect(config.get("filterhitstats", "dbuser"),
-               config.get("filterhitstats", "dbpassword"),
-               config.get("filterhitstats", "database"))
-    db.write(geometrical_mean.update(interval, data))
-  except MySQLdb.Error, e:
+    db_connection = db.connect()
+    try:
+      db.write(db_connection, geometrical_mean.update(interval, data))
+    finally:
+      db_connection.close()
+  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.
-    mysql_error_log = os.path.join(config.get("filterhitstats", "log_dir"),
-                                   "mysql-errors.log")
-    with open(mysql_error_log, "a+") as f:
-      f.write("[%s] MySQL error (%d) when processing data file %s: \"%s\"\n" % (
-        datetime.now().strftime('%d/%b/%Y:%H:%M:%S %z'),
-        e.args[0], log_file, e.args[1]
-      ))
-  finally:
-    db.disconnect()
+    # 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 []