From 8aec4a45d2bc096b5f33d4a5e48c629437036e8e Mon Sep 17 00:00:00 2001 From: Aaron Kimbre Date: Fri, 11 Feb 2022 20:31:57 -0600 Subject: [PATCH] General Logging some extra logging around problem areas --- .gitignore | 1 + app/__init__.py | 45 +++++++++-- app/accounts.py | 2 +- app/reports.py | 194 +++++++++++++++++++++++++----------------------- 4 files changed, 144 insertions(+), 98 deletions(-) diff --git a/.gitignore b/.gitignore index 03e6e85..3f98055 100644 --- a/.gitignore +++ b/.gitignore @@ -14,3 +14,4 @@ locale.xml app/luclient/* app/cache/* property_files/* +*.log diff --git a/app/__init__.py b/app/__init__.py index ed5c7a2..200a280 100644 --- a/app/__init__.py +++ b/app/__init__.py @@ -1,5 +1,5 @@ import os -from flask import Flask, url_for, g, redirect +from flask import Flask, url_for, g, redirect, render_template from functools import wraps from flask_assets import Environment from webassets import Bundle @@ -7,7 +7,7 @@ import time from app.models import db, migrate, PlayKey from app.schemas import ma from app.forms import CustomUserManager -from flask_user import user_registered, current_user +from flask_user import user_registered, current_user, user_logged_in from flask_wtf.csrf import CSRFProtect from flask_apscheduler import APScheduler from app.luclient import query_cdclient, register_luclient_jinja_helpers @@ -15,6 +15,11 @@ from app.luclient import query_cdclient, register_luclient_jinja_helpers from app.commands import init_db, init_accounts, load_property, gen_image_cache, gen_model_cache from app.models import Account, AccountInvitation +import logging +from logging.handlers import RotatingFileHandler + +from werkzeug.exceptions import HTTPException + # Instantiate Flask extensions csrf_protect = CSRFProtect() scheduler = APScheduler() @@ -22,7 +27,6 @@ scheduler = APScheduler() def create_app(): - app = Flask(__name__, instance_relative_config=True) # decrement uses on a play key after a successful registration @@ -33,8 +37,19 @@ def create_app(): play_key_used = PlayKey.query.filter(PlayKey.id == user.play_key_id).first() play_key_used.key_uses = play_key_used.key_uses - 1 play_key_used.times_used = play_key_used.times_used + 1 + app.logger.info( + f"USERS::REGISTRATION User with ID {user.id} and name {user.username} Registered \ + using Play Key ID {play_key_used.id} : {play_key_used.key_string}" + ) db.session.add(play_key_used) db.session.commit() + else: + app.logger.info(f"USERS::REGISTRATION User with ID {user.id} and name {user.username} Registered") + + + @user_logged_in.connect_via(app) + def _after_login_hook(sender, user, **extra): + app.logger.info(f"{user.username} Logged in") # A bunch of jinja filters to make things easiers @app.template_filter('ctime') @@ -51,15 +66,24 @@ def create_app(): else: return 0 & (1 << bit) + @app.template_filter('debug') + def debug(text): + print(text) + @app.teardown_appcontext def close_connection(exception): cdclient = getattr(g, '_cdclient', None) if cdclient is not None: cdclient.close() - @app.template_filter('debug') - def debug(text): - print(text) + @app.errorhandler(Exception) + def handle_exception(e): + app.logger.error(e) + # pass through HTTP errors + if isinstance(e, HTTPException): + return e + # now you're handling non-HTTP exceptions only + return render_template("status_codes/500.html.j2", exception=e), 500 # add the commands to flask cli app.cli.add_command(init_db) @@ -68,6 +92,7 @@ def create_app(): app.cli.add_command(gen_image_cache) app.cli.add_command(gen_model_cache) + register_logging(app) register_settings(app) register_extensions(app) register_blueprints(app) @@ -132,6 +157,14 @@ def register_blueprints(app): app.register_blueprint(reports_blueprint, url_prefix='/reports') +def register_logging(app): + # file logger + file_handler = RotatingFileHandler('nexus_dashboard.log', maxBytes=1024 * 1024 * 100, backupCount=20) + file_handler.setLevel(logging.INFO) + formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") + file_handler.setFormatter(formatter) + app.logger.addHandler(file_handler) + def register_settings(app): """Register setting from setting and env diff --git a/app/accounts.py b/app/accounts.py index 3e52560..c25ff21 100644 --- a/app/accounts.py +++ b/app/accounts.py @@ -1,4 +1,4 @@ -from flask import render_template, Blueprint, redirect, url_for, request, abort, current_app, flash +from flask import render_template, Blueprint, redirect, url_for, request, abort, current_app, flash, current_app from flask_user import login_required, current_user import json from datatables import ColumnDT, DataTables diff --git a/app/reports.py b/app/reports.py index dd2ffd3..069288b 100644 --- a/app/reports.py +++ b/app/reports.py @@ -1,4 +1,4 @@ -from flask import render_template, Blueprint, redirect, url_for, request, abort, flash, request +from flask import render_template, Blueprint, redirect, url_for, request, abort, flash, request, current_app from flask_user import login_required, current_user from app.models import db, CharacterInfo, Account, CharacterXML, Reports from app import gm_level, scheduler @@ -37,119 +37,131 @@ def uscore_by_date(date): @scheduler.task("cron", id="gen_item_report", hour=23) def gen_item_report(): - with scheduler.app.app_context(): - date = datetime.date.today().strftime('%Y-%m-%d') - report = Reports.query.filter(Reports.date==date).filter(Reports.report_type=="items").first() + try: + current_app.logger.info("Start Item Report Generation") + with scheduler.app.app_context(): + date = datetime.date.today().strftime('%Y-%m-%d') + report = Reports.query.filter(Reports.date==date).filter(Reports.report_type=="items").first() - # Only one report per day - if report != None: - return f"Item Report Already Generated for {date}" + # Only one report per day + if report != None: + current_app.logger.info(f"Item Report Already Generated for {date}") - char_xmls = CharacterXML.query.join( - CharacterInfo, - CharacterInfo.id==CharacterXML.id - ).join( - Account, - CharacterInfo.account_id==Account.id - ).filter(Account.gm_level < 3).all() + char_xmls = CharacterXML.query.join( + CharacterInfo, + CharacterInfo.id==CharacterXML.id + ).join( + Account, + CharacterInfo.account_id==Account.id + ).filter(Account.gm_level < 3).all() - report_data={} + report_data={} - for char_xml in char_xmls: - character_json = xmltodict.parse( - char_xml.xml_data, - attr_prefix="attr_" + for char_xml in char_xmls: + character_json = xmltodict.parse( + char_xml.xml_data, + attr_prefix="attr_" + ) + for inv in character_json["obj"]["inv"]["items"]["in"]: + if "i" in inv.keys() and type(inv["i"]) == list and (int(inv["attr_t"])==0 or int(inv["attr_t"])==0): + for item in inv["i"]: + if item["attr_l"] in report_data: + report_data[item["attr_l"]] = report_data[item["attr_l"]] + int(item["attr_c"]) + else: + report_data[item["attr_l"]] = int(item["attr_c"]) + + new_report = Reports( + data=report_data, + report_type="items", + date=date ) - for inv in character_json["obj"]["inv"]["items"]["in"]: - if "i" in inv.keys() and type(inv["i"]) == list and (int(inv["attr_t"])==0 or int(inv["attr_t"])==0): - for item in inv["i"]: - if item["attr_l"] in report_data: - report_data[item["attr_l"]] = report_data[item["attr_l"]] + int(item["attr_c"]) - else: - report_data[item["attr_l"]] = int(item["attr_c"]) - new_report = Reports( - data=report_data, - report_type="items", - date=date - ) - - new_report.save() - - return f"Generated Item Report for {date}" + new_report.save() + current_app.logger.info(f"Generated Item Report for {date}") + except Exception as e: + current_app.logger.critical(f"REPORT::ITEMS - {e}") + return @scheduler.task("cron", id="gen_currency_report", hour=23) def gen_currency_report(): - with scheduler.app.app_context(): - date = datetime.date.today().strftime('%Y-%m-%d') - report = Reports.query.filter(Reports.date==date).filter(Reports.report_type=="currency").first() + try: + current_app.logger.info("Start Currency Report Generation") + with scheduler.app.app_context(): + date = datetime.date.today().strftime('%Y-%m-%d') + report = Reports.query.filter(Reports.date==date).filter(Reports.report_type=="currency").first() - # Only one report per day - if report != None: - return f"Currency Report Already Generated for {date}" + # Only one report per day + if report != None: + current_app.logger.info(f"Currency Report Already Generated for {date}") - characters = CharacterXML.query.join( - CharacterInfo, - CharacterInfo.id==CharacterXML.id - ).join( - Account, - CharacterInfo.account_id==Account.id - ).filter(Account.gm_level < 3).all() + characters = CharacterXML.query.join( + CharacterInfo, + CharacterInfo.id==CharacterXML.id + ).join( + Account, + CharacterInfo.account_id==Account.id + ).filter(Account.gm_level < 3).all() - report_data={} + report_data={} - for character in characters: - character_json = xmltodict.parse( - character.xml_data, - attr_prefix="attr_" + for character in characters: + character_json = xmltodict.parse( + character.xml_data, + attr_prefix="attr_" + ) + report_data[CharacterInfo.query.filter(CharacterInfo.id==character.id).first().name] = int(character_json["obj"]["char"]["attr_cc"]) + + new_report = Reports( + data=report_data, + report_type="currency", + date=date ) - report_data[CharacterInfo.query.filter(CharacterInfo.id==character.id).first().name] = int(character_json["obj"]["char"]["attr_cc"]) - new_report = Reports( - data=report_data, - report_type="currency", - date=date - ) - - new_report.save() - - return f"Generated Currency Report for {date}" + new_report.save() + current_app.logger.info(f"Generated Currency Report for {date}") + except Exception as e: + current_app.logger.critical(f"REPORT::CURRENCY - {e}") + return @scheduler.task("cron", id="gen_uscore_report", hour=23) def gen_uscore_report(): - with scheduler.app.app_context(): - date = datetime.date.today().strftime('%Y-%m-%d') - report = Reports.query.filter(Reports.date==date).filter(Reports.report_type=="uscore").first() + try: + current_app.logger.info("Start U-Score Report Generation") + with scheduler.app.app_context(): + date = datetime.date.today().strftime('%Y-%m-%d') + report = Reports.query.filter(Reports.date==date).filter(Reports.report_type=="uscore").first() - # Only one report per day - if report != None: - return f"U-Score Report Already Generated for {date}" + # Only one report per day + if report != None: + current_app.logger.info(f"U-Score Report Already Generated for {date}") - characters = CharacterXML.query.join( - CharacterInfo, - CharacterInfo.id==CharacterXML.id - ).join( - Account, - CharacterInfo.account_id==Account.id - ).filter(Account.gm_level < 3).all() + characters = CharacterXML.query.join( + CharacterInfo, + CharacterInfo.id==CharacterXML.id + ).join( + Account, + CharacterInfo.account_id==Account.id + ).filter(Account.gm_level < 3).all() - report_data={} + report_data={} - for character in characters: - character_json = xmltodict.parse( - character.xml_data, - attr_prefix="attr_" + for character in characters: + character_json = xmltodict.parse( + character.xml_data, + attr_prefix="attr_" + ) + report_data[CharacterInfo.query.filter(CharacterInfo.id==character.id).first().name] = int(character_json["obj"]["char"]["attr_ls"]) + + new_report = Reports( + data=report_data, + report_type="uscore", + date=date ) - report_data[CharacterInfo.query.filter(CharacterInfo.id==character.id).first().name] = int(character_json["obj"]["char"]["attr_ls"]) - new_report = Reports( - data=report_data, - report_type="uscore", - date=date - ) - - new_report.save() - - return f"Generated U-Score Report for {date}" + new_report.save() + current_app.logger.info(f"Generated U-Score Report for {date}") + except Exception as e: + current_app.logger.critical(f"REPORT::U-SCORE - {e}") + return