Commit 2063196c authored by Mickaël Desfrênes's avatar Mickaël Desfrênes
Browse files

better logging

parent f882b5e1

.gitignore

+3 −1
Original line number Diff line number Diff line
@@ -5,3 +5,5 @@ venv 
.DS_Store

partial_uploads

iiif

*.log

media_source_files
 
 No newline at end of file

jama/settings.py

+28 −1
Original line number Diff line number Diff line
@@ -40,7 +40,7 @@ SECRET_KEY = ( 
DEBUG = True if os.getenv("JAMA_DEBUG") == "1" else False



JAMA_IIIF_ENDPOINT = os.getenv("JAMA_IIIF_ENDPOINT") or "http://localhost/iip/IIIF="



JAMA_LOG_FILE = os.getenv("JAMA_LOG_FILE") or "sql.log"

ALLOWED_HOSTS = ["*"]
@@ -176,3 +176,30 @@ USE_TZ = True 


STATIC_ROOT = "{}/static/".format(BASE_DIR)

STATIC_URL = JAMA_URL_BASE_PATH + "/static/"





LOGGING = {

    "version": 1,

    "disable_existing_loggers": False,

    "formatters": {

        "console": {"format": "%(asctime)s %(name)-12s %(levelname)-8s %(message)s"},

        "file": {"format": "%(asctime)s %(name)-12s %(levelname)-8s %(message)s"},

    },

    "handlers": {

        "console": {

            "level": "INFO",

            "class": "logging.StreamHandler",

            "formatter": "console",

        },

        "file": {

            "level": "DEBUG",

            "class": "logging.FileHandler",

            "formatter": "file",

            "filename": JAMA_LOG_FILE,

        },

    },

    "loggers": {

        "": {"level": "INFO", "handlers": ["console"]},

        "rpc.sql": {"level": "DEBUG", "handlers": ["file"]},

    },

}

rpc/methods.py

+13 −6
Original line number Diff line number Diff line
@@ -25,9 +25,12 @@ import re 
from glob import glob as _glob

import unidecode

from rpc.cache import SerializerCache



from inspect import signature

from functools import wraps as _wraps

from rpc.const import *

import logging



logger = logging.getLogger(__name__)





class ServiceException(Exception):
@@ -59,10 +62,14 @@ def _log_call(func): 


    @_wraps(func)

    def wrapper(*args, **kwargs):

        if settings.DEBUG:

            print(

                'RPC method "{}", called by {} (user #{}) with params {}.'.format(

                    func.__name__, args[0].username, args[0].pk, args[1:]

        sign = signature(func)

        param_names = []

        for param in list(sign.parameters.items())[1:]:

            param_names.append(param[0])

        params_dict = dict(zip(param_names, args[1:]))

        logger.info(

            'User {}({}) called "{}" with params {}.'.format(

                args[0].username, args[0].pk, func.__name__, params_dict

            )

        )

        return func(*args, **kwargs)

rpc/views.py

+28 −19
Original line number Diff line number Diff line
@@ -29,6 +29,9 @@ from shutil import rmtree 
import base64

from ranged_fileresponse import RangedFileResponse

from django.views.decorators.gzip import gzip_page

import logging



logger = logging.getLogger(__name__)





def _silent_rmdir(dir_path: str):
@@ -45,9 +48,9 @@ def _silent_remove(file_path: str): 
def _debug_sql():

    if not settings.SHOW_SQL:

        return

    print("")

    print("#--- Start PostgreSQL Queries ---#")

    print("")

    logger = logging.getLogger("rpc.sql")

    out = "#--- Start PostgreSQL Queries ---#"

    out += "\n"

    req_count = 0

    req_mult_count = {}

    has_doubled_queries = False
@@ -57,18 +60,20 @@ def _debug_sql(): 
            has_doubled_queries = True

        else:

            req_mult_count[query["sql"]] = 1

        print("")

        print(" ", query["sql"])

        print("")

        out += "\n"

        out += "\n" + query["sql"]

        out += "\n"

        req_count = req_count + 1

    print("#--- End PostgreSQL Queries ({} queries) ---#".format(req_count))

    out += "\n#--- End PostgreSQL Queries ({} queries) ---#".format(req_count)

    if has_doubled_queries:

        print("")

        print("Queries being doubled:")

        print("")

        out += "\n"

        out += "\nQueries being doubled:"

        out += "\n"

        for k, v in req_mult_count.items():

            if v > 1:

                print("({} times): {}".format(v, k))

                out += "\n({} times): {}".format(v, k)

    out += "\n"

    logger.debug(out)





def _file_hash256(file_path: str) -> str:
@@ -183,14 +188,18 @@ def rpc(request: HttpRequest) -> HttpResponse: 
        result = methods[method](*params)

        _debug_sql()

        return JsonResponse({"result": result, "error": None, "id": req_id})

    # except json.JSONDecodeError:

    #    return HttpResponse("Bad Request", status=400)

    # except KeyError:

    #    return HttpResponse("Bad Request", status=400)

    # except TypeError:

    #    return HttpResponse("Bad Request", status=400)

    # except ValueError:

    #    return HttpResponse("Bad Request", status=400)

    except json.JSONDecodeError:

        logger.warning("could not decode json request")

        return HttpResponse("Bad Request", status=400)

    except KeyError:

        logger.warning("client data dict key error")

        return HttpResponse("Bad Request", status=400)

    except TypeError:

        logger.warning("client data type error")

        return HttpResponse("Bad Request", status=400)

    except ValueError:

        logger.warning("client data warning error")

        return HttpResponse("Bad Request", status=400)

    except ServiceException as e:

        return JsonResponse(

            {