mirror of
https://github.com/evennia/evennia.git
synced 2026-03-24 08:46:31 +01:00
Update logger.py to use new Twisted log api. No change in evennia-side usage
This commit is contained in:
Griatch
parent
7aad2b9d10
commit
17f0ce8245
6 changed files with 230 additions and 210 deletions
|
|
@ -153,6 +153,8 @@ Up requirements to Django 4.0+, Twisted 22+, Python 3.9 or 3.10
|
|||
decouple structures from database without needing separate import.
|
||||
- Add `run_in_main_thread` as a helper for those wanting to code server code
|
||||
from a web view.
|
||||
- Update `evennia.utils.logger` to use Twisted's new logging API. No change in Evennia API
|
||||
except more standard aliases logger.error/info/exception/debug etc can now be used.
|
||||
|
||||
|
||||
## Evennia 0.9.5
|
||||
|
|
|
|||
|
|
@ -15,7 +15,7 @@ from os.path import dirname, abspath
|
|||
from twisted.application import internet, service
|
||||
from twisted.internet.task import LoopingCall
|
||||
from twisted.internet import protocol, reactor
|
||||
from twisted.python.log import ILogObserver
|
||||
from twisted.logger import globalLogPublisher
|
||||
|
||||
import django
|
||||
|
||||
|
|
@ -245,16 +245,17 @@ class Portal(object):
|
|||
# what to execute from.
|
||||
application = service.Application("Portal")
|
||||
|
||||
# custom logging
|
||||
|
||||
if "--nodaemon" not in sys.argv:
|
||||
if ("--nodaemon" not in sys.argv
|
||||
and not hasattr(settings, "_TEST_ENVIRONMENT") and settings._TEST_ENVIRONMENT):
|
||||
# custom logging
|
||||
logfile = logger.WeeklyLogFile(
|
||||
os.path.basename(settings.PORTAL_LOG_FILE),
|
||||
os.path.dirname(settings.PORTAL_LOG_FILE),
|
||||
day_rotation=settings.PORTAL_LOG_DAY_ROTATION,
|
||||
max_size=settings.PORTAL_LOG_MAX_SIZE,
|
||||
)
|
||||
application.setComponent(ILogObserver, logger.PortalLogObserver(logfile).emit)
|
||||
globalLogPublisher.addObserver(logger.GetPortalLogObserver()(logfile))
|
||||
|
||||
# The main Portal server program. This sets up the database
|
||||
# and is where we store all the other services.
|
||||
|
|
|
|||
|
|
@ -16,7 +16,7 @@ from twisted.web import static
|
|||
from twisted.application import internet, service
|
||||
from twisted.internet import reactor, defer
|
||||
from twisted.internet.task import LoopingCall
|
||||
from twisted.python.log import ILogObserver
|
||||
from twisted.logger import globalLogPublisher
|
||||
|
||||
import django
|
||||
|
||||
|
|
@ -647,7 +647,8 @@ except OperationalError:
|
|||
# what to execute from.
|
||||
application = service.Application("Evennia")
|
||||
|
||||
if "--nodaemon" not in sys.argv:
|
||||
if ("--nodaemon" not in sys.argv
|
||||
and not hasattr(settings, "_TEST_ENVIRONMENT") and settings._TEST_ENVIRONMENT):
|
||||
# custom logging, but only if we are not running in interactive mode
|
||||
logfile = logger.WeeklyLogFile(
|
||||
os.path.basename(settings.SERVER_LOG_FILE),
|
||||
|
|
@ -655,7 +656,8 @@ if "--nodaemon" not in sys.argv:
|
|||
day_rotation=settings.SERVER_LOG_DAY_ROTATION,
|
||||
max_size=settings.SERVER_LOG_MAX_SIZE,
|
||||
)
|
||||
application.setComponent(ILogObserver, logger.ServerLogObserver(logfile).emit)
|
||||
globalLogPublisher.addObserver(logger.GetServerLogObserver()(logfile))
|
||||
|
||||
|
||||
# The main evennia server program. This sets up the database
|
||||
# and is where we store all the other services.
|
||||
|
|
|
|||
|
|
@ -16,20 +16,27 @@ class EvenniaTestSuiteRunner(DiscoverRunner):
|
|||
avoid running the large number of tests defined by Django
|
||||
|
||||
"""
|
||||
|
||||
def build_suite(self, test_labels, extra_tests=None, **kwargs):
|
||||
"""
|
||||
Build a test suite for Evennia. test_labels is a list of apps to test.
|
||||
If not given, a subset of settings.INSTALLED_APPS will be used.
|
||||
"""
|
||||
def setup_test_environment(self, **kwargs):
|
||||
# the portal looping call starts before the unit-test suite so we
|
||||
# can't mock it - instead we stop it before starting the test - otherwise
|
||||
# we'd get unclean reactor errors across test boundaries.
|
||||
from evennia.server.portal.portal import PORTAL
|
||||
|
||||
PORTAL.maintenance_task.stop()
|
||||
|
||||
# initialize evennia itself
|
||||
import evennia
|
||||
|
||||
evennia._init()
|
||||
return super().build_suite(test_labels, extra_tests=extra_tests, **kwargs)
|
||||
|
||||
from django.conf import settings
|
||||
|
||||
# set testing flag while suite runs
|
||||
settings._TEST_ENVIRONMENT = True
|
||||
super().setup_test_environment(**kwargs)
|
||||
|
||||
def teardown_test_environment(self, **kwargs):
|
||||
|
||||
# remove testing flag after suite has run
|
||||
from django.conf import settings
|
||||
settings._TEST_ENVIRONMENT = False
|
||||
|
||||
super().teardown_test_environment(**kwargs)
|
||||
|
|
|
|||
|
|
@ -18,16 +18,213 @@ import os
|
|||
import time
|
||||
from datetime import datetime
|
||||
from traceback import format_exc
|
||||
from twisted.python import log, logfile
|
||||
from twisted import logger as twisted_logger
|
||||
from twisted.python import logfile
|
||||
from twisted.python import util as twisted_util
|
||||
from twisted.internet.threads import deferToThread
|
||||
|
||||
log = twisted_logger.Logger()
|
||||
|
||||
_LOGDIR = None
|
||||
_LOG_ROTATE_SIZE = None
|
||||
_TIMEZONE = None
|
||||
_CHANNEL_LOG_NUM_TAIL_LINES = None
|
||||
|
||||
_TIME_FORMAT = "%Y-%m-%d %H:%M:%S"
|
||||
|
||||
|
||||
def _log(msg, logfunc, prefix="", **kwargs):
|
||||
try:
|
||||
msg = str(msg)
|
||||
except Exception as err:
|
||||
msg = str(e)
|
||||
if kwargs:
|
||||
logfunc(msg, **kwargs)
|
||||
else:
|
||||
try:
|
||||
for line in msg.splitlines():
|
||||
logfunc("{line}", prefix=prefix, line=line)
|
||||
except Exception as err:
|
||||
log.error("Log failure: {err}", err=err)
|
||||
|
||||
|
||||
# log call functions (each has legacy aliases)
|
||||
|
||||
def log_info(msg, **kwargs):
|
||||
"""
|
||||
Logs any generic debugging/informative info that should appear in the log.
|
||||
|
||||
Args:
|
||||
msg: (string) The message to be logged.
|
||||
**kwargs: If given, The `msg` is parsed as a format string with `{..}`
|
||||
formatting markers that should match the keywords.
|
||||
|
||||
"""
|
||||
_log(msg, log.info, **kwargs)
|
||||
|
||||
info = log_info
|
||||
log_infomsg = log_info
|
||||
log_msg = log_info
|
||||
|
||||
|
||||
def log_warn(msg, **kwargs):
|
||||
"""
|
||||
Logs warnings that aren't critical but should be noted.
|
||||
|
||||
Args:
|
||||
msg (str): The message to be logged.
|
||||
**kwargs: If given, The `msg` is parsed as a format string with `{..}`
|
||||
formatting markers that should match the keywords.
|
||||
|
||||
"""
|
||||
_log(msg, log.warn, **kwargs)
|
||||
|
||||
warn = log_warn
|
||||
warning = log_warn
|
||||
log_warnmsg = log_warn
|
||||
|
||||
|
||||
def log_err(msg, **kwargs):
|
||||
"""
|
||||
Logs an error message to the server log.
|
||||
|
||||
Args:
|
||||
msg (str): The message to be logged.
|
||||
**kwargs: If given, The `msg` is parsed as a format string with `{..}`
|
||||
formatting markers that should match the keywords.
|
||||
|
||||
"""
|
||||
_log(msg, log.error, **kwargs)
|
||||
|
||||
|
||||
error = log_err
|
||||
err = log_err
|
||||
log_errmsg = log_err
|
||||
|
||||
|
||||
def log_trace(msg=None, **kwargs):
|
||||
"""
|
||||
Log a traceback to the log. This should be called from within an
|
||||
exception.
|
||||
|
||||
Args:
|
||||
msg (str, optional): Adds an extra line with added info
|
||||
at the end of the traceback in the log.
|
||||
**kwargs: If given, The `msg` is parsed as a format string with `{..}`
|
||||
formatting markers that should match the keywords.
|
||||
|
||||
"""
|
||||
tracestring = format_exc()
|
||||
if tracestring:
|
||||
_log(tracestring, log.error, prefix="!!", **kwargs)
|
||||
if msg:
|
||||
_log(msg, log.error, prefix="!!", **kwargs)
|
||||
|
||||
log_tracemsg = log_trace
|
||||
exception = log_trace
|
||||
critical = log_trace
|
||||
trace = log_trace
|
||||
|
||||
|
||||
def log_dep(msg, **kwargs):
|
||||
"""
|
||||
Prints a deprecation message.
|
||||
|
||||
Args:
|
||||
msg (str): The deprecation message to log.
|
||||
**kwargs: If given, The `msg` is parsed as a format string with `{..}`
|
||||
formatting markers that should match the keywords.
|
||||
|
||||
"""
|
||||
_log(msg, log.warn, prefix="DP", **kwargs)
|
||||
|
||||
|
||||
dep = log_dep
|
||||
deprecated = log_dep
|
||||
log_depmsg = log_dep
|
||||
|
||||
|
||||
def log_sec(msg, **kwargs):
|
||||
"""
|
||||
Prints a security-related message.
|
||||
|
||||
Args:
|
||||
msg (str): The security message to log.
|
||||
**kwargs: If given, The `msg` is parsed as a format string with `{..}`
|
||||
formatting markers that should match the keywords.
|
||||
|
||||
"""
|
||||
_log(msg, log.info, prefix="SS", **kwargs)
|
||||
|
||||
sec = log_sec
|
||||
security = log_sec
|
||||
log_secmsg = log_sec
|
||||
|
||||
|
||||
def log_server(msg, **kwargs):
|
||||
"""
|
||||
This is for the Portal to log captured Server stdout messages (it's
|
||||
usually only used during startup, before Server log is open)
|
||||
|
||||
Args:
|
||||
msg (str): The message to be logged.
|
||||
**kwargs: If given, The `msg` is parsed as a format string with `{..}`
|
||||
formatting markers that should match the keywords.
|
||||
"""
|
||||
_log(msg, log.info, prefix="Server", **kwargs)
|
||||
|
||||
|
||||
|
||||
class GetLogObserver:
|
||||
"""
|
||||
Sets up how the system logs are formatted.
|
||||
|
||||
"""
|
||||
component_prefix = ""
|
||||
event_levels = {
|
||||
twisted_logger.LogLevel.debug: "??",
|
||||
twisted_logger.LogLevel.info: "..",
|
||||
twisted_logger.LogLevel.warn: "WW",
|
||||
twisted_logger.LogLevel.error: "EE",
|
||||
twisted_logger.LogLevel.critical: "!!",
|
||||
}
|
||||
|
||||
def format_log_event(self, event):
|
||||
"""
|
||||
By assigning log_system here, we skip the spammy display of namespace/level
|
||||
in the default log output.
|
||||
|
||||
[component_prefix] [date] [system/lvl] [msg]
|
||||
|
||||
"""
|
||||
# setting log_system fills the [..] block after the time stamp
|
||||
prefix = event.get("prefix", "")
|
||||
if prefix:
|
||||
event["log_system"] = prefix
|
||||
else:
|
||||
lvl = event.get("log_level", twisted_logger.LogLevel.info)
|
||||
event["log_system"] = self.event_levels.get(lvl, "-")
|
||||
event["log_format"] = str(event.get("log_format", ""))
|
||||
component_prefix = self.component_prefix or ""
|
||||
|
||||
return component_prefix + twisted_logger.formatEventAsClassicLogText(
|
||||
event,
|
||||
formatTime=lambda e: twisted_logger.formatTime(e, _TIME_FORMAT)
|
||||
)
|
||||
|
||||
def __call__(self, outfile):
|
||||
return twisted_logger.FileLogObserver(outfile, self.format_log_event)
|
||||
|
||||
|
||||
# Called by server/portal on startup
|
||||
|
||||
class GetPortalLogObserver(GetLogObserver):
|
||||
component_prefix = "|Portal| "
|
||||
|
||||
class GetServerLogObserver(GetLogObserver):
|
||||
component_prefix = ""
|
||||
|
||||
|
||||
|
||||
# logging overrides
|
||||
|
||||
|
|
@ -37,7 +234,7 @@ def timeformat(when=None):
|
|||
This helper function will format the current time in the same
|
||||
way as the twisted logger does, including time zone info. Only
|
||||
difference from official logger is that we only use two digits
|
||||
for the year and don't show timezone for CET times.
|
||||
for the year and don't show timezone for GMT times.
|
||||
|
||||
Args:
|
||||
when (int, optional): This is a time in POSIX seconds on the form
|
||||
|
|
@ -155,196 +352,6 @@ class WeeklyLogFile(logfile.DailyLogFile):
|
|||
self.lastDate = max(self.lastDate, self.toDate())
|
||||
self.size += len(data)
|
||||
|
||||
|
||||
class PortalLogObserver(log.FileLogObserver):
|
||||
"""
|
||||
Reformat logging
|
||||
|
||||
"""
|
||||
|
||||
timeFormat = None
|
||||
prefix = " |Portal| "
|
||||
|
||||
def emit(self, eventDict):
|
||||
"""
|
||||
Copied from Twisted parent, to change logging output
|
||||
|
||||
"""
|
||||
text = log.textFromEventDict(eventDict)
|
||||
if text is None:
|
||||
return
|
||||
|
||||
# timeStr = self.formatTime(eventDict["time"])
|
||||
timeStr = timeformat(eventDict["time"])
|
||||
fmtDict = {"text": text.replace("\n", "\n\t")}
|
||||
|
||||
msgStr = log._safeFormat("%(text)s\n", fmtDict)
|
||||
|
||||
twisted_util.untilConcludes(self.write, timeStr + "%s" % self.prefix + msgStr)
|
||||
twisted_util.untilConcludes(self.flush)
|
||||
|
||||
|
||||
class ServerLogObserver(PortalLogObserver):
|
||||
prefix = " "
|
||||
|
||||
|
||||
def log_msg(msg):
|
||||
"""
|
||||
Wrapper around log.msg call to catch any exceptions that might
|
||||
occur in logging. If an exception is raised, we'll print to
|
||||
stdout instead.
|
||||
|
||||
Args:
|
||||
msg: The message that was passed to log.msg
|
||||
|
||||
"""
|
||||
try:
|
||||
log.msg(msg)
|
||||
except Exception:
|
||||
print("Exception raised while writing message to log. Original message: %s" % msg)
|
||||
|
||||
|
||||
def log_trace(errmsg=None):
|
||||
"""
|
||||
Log a traceback to the log. This should be called from within an
|
||||
exception.
|
||||
|
||||
Args:
|
||||
errmsg (str, optional): Adds an extra line with added info
|
||||
at the end of the traceback in the log.
|
||||
|
||||
"""
|
||||
tracestring = format_exc()
|
||||
try:
|
||||
if tracestring:
|
||||
for line in tracestring.splitlines():
|
||||
log.msg("[::] %s" % line)
|
||||
if errmsg:
|
||||
try:
|
||||
errmsg = str(errmsg)
|
||||
except Exception as e:
|
||||
errmsg = str(e)
|
||||
for line in errmsg.splitlines():
|
||||
log_msg("[EE] %s" % line)
|
||||
except Exception:
|
||||
log_msg("[EE] %s" % errmsg)
|
||||
|
||||
|
||||
log_tracemsg = log_trace
|
||||
|
||||
|
||||
def log_err(errmsg):
|
||||
"""
|
||||
Prints/logs an error message to the server log.
|
||||
|
||||
Args:
|
||||
errmsg (str): The message to be logged.
|
||||
|
||||
"""
|
||||
try:
|
||||
errmsg = str(errmsg)
|
||||
except Exception as e:
|
||||
errmsg = str(e)
|
||||
for line in errmsg.splitlines():
|
||||
log_msg("[EE] %s" % line)
|
||||
|
||||
# log.err('ERROR: %s' % (errmsg,))
|
||||
|
||||
|
||||
log_errmsg = log_err
|
||||
|
||||
|
||||
def log_server(servermsg):
|
||||
"""
|
||||
This is for the Portal to log captured Server stdout messages (it's
|
||||
usually only used during startup, before Server log is open)
|
||||
|
||||
"""
|
||||
try:
|
||||
servermsg = str(servermsg)
|
||||
except Exception as e:
|
||||
servermsg = str(e)
|
||||
for line in servermsg.splitlines():
|
||||
log_msg("[Server] %s" % line)
|
||||
|
||||
|
||||
def log_warn(warnmsg):
|
||||
"""
|
||||
Prints/logs any warnings that aren't critical but should be noted.
|
||||
|
||||
Args:
|
||||
warnmsg (str): The message to be logged.
|
||||
|
||||
"""
|
||||
try:
|
||||
warnmsg = str(warnmsg)
|
||||
except Exception as e:
|
||||
warnmsg = str(e)
|
||||
for line in warnmsg.splitlines():
|
||||
log_msg("[WW] %s" % line)
|
||||
|
||||
# log.msg('WARNING: %s' % (warnmsg,))
|
||||
|
||||
|
||||
log_warnmsg = log_warn
|
||||
|
||||
|
||||
def log_info(infomsg):
|
||||
"""
|
||||
Prints any generic debugging/informative info that should appear in the log.
|
||||
|
||||
infomsg: (string) The message to be logged.
|
||||
|
||||
"""
|
||||
try:
|
||||
infomsg = str(infomsg)
|
||||
except Exception as e:
|
||||
infomsg = str(e)
|
||||
for line in infomsg.splitlines():
|
||||
log_msg("[..] %s" % line)
|
||||
|
||||
|
||||
log_infomsg = log_info
|
||||
|
||||
|
||||
def log_dep(depmsg):
|
||||
"""
|
||||
Prints a deprecation message.
|
||||
|
||||
Args:
|
||||
depmsg (str): The deprecation message to log.
|
||||
|
||||
"""
|
||||
try:
|
||||
depmsg = str(depmsg)
|
||||
except Exception as e:
|
||||
depmsg = str(e)
|
||||
for line in depmsg.splitlines():
|
||||
log_msg("[DP] %s" % line)
|
||||
|
||||
|
||||
log_depmsg = log_dep
|
||||
|
||||
|
||||
def log_sec(secmsg):
|
||||
"""
|
||||
Prints a security-related message.
|
||||
|
||||
Args:
|
||||
secmsg (str): The security message to log.
|
||||
|
||||
"""
|
||||
try:
|
||||
secmsg = str(secmsg)
|
||||
except Exception as e:
|
||||
secmsg = str(e)
|
||||
for line in secmsg.splitlines():
|
||||
log_msg("[SS] %s" % line)
|
||||
|
||||
|
||||
log_secmsg = log_sec
|
||||
|
||||
|
||||
# Arbitrary file logger
|
||||
|
||||
|
||||
|
|
|
|||
|
|
@ -96,8 +96,9 @@ DEFAULT_SETTING_RESETS = dict(
|
|||
"evennia.game_template.server.conf.prototypefuncs",
|
||||
],
|
||||
BASE_GUEST_TYPECLASS="evennia.accounts.accounts.DefaultGuest",
|
||||
# a special flag; test with settings._TEST_ENVIRONMENT to see if code runs in a test
|
||||
_TEST_ENVIRONMENT=True,
|
||||
|
||||
# a special setting boolean _TEST_ENVIRONMENT is set by the test runner
|
||||
# while the test suite is running.
|
||||
)
|
||||
|
||||
DEFAULT_SETTINGS = {**all_from_module(settings_default), **DEFAULT_SETTING_RESETS}
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue