Mercurial > p > roundup > code
changeset 8488:7142740e6547
merge heads: CHANGES.txt also whitespace fixups.
| author | John Rouillard <rouilj@ieee.org> |
|---|---|
| date | Mon, 08 Dec 2025 23:05:26 -0500 |
| parents | e2d0f36c525d (current diff) b09ef85f0da6 (diff) |
| children | 4e0944649af7 |
| files | CHANGES.txt doc/admin_guide.txt doc/installation.txt roundup/configuration.py |
| diffstat | 8 files changed, 138 insertions(+), 31 deletions(-) [+] |
line wrap: on
line diff
--- a/CHANGES.txt Sun Dec 07 17:33:25 2025 -0500 +++ b/CHANGES.txt Mon Dec 08 23:05:26 2025 -0500 @@ -54,9 +54,10 @@ logging format. (John Rouillard) - the default logging format template includes an identifier unique for a request. This identifier (trace_id) can be use to identify - logs for a specific transaction. Logging also supports a - trace_reason log token with the url for a web request. The logging - format can be changed in config.ini. (John Rouillard) + logs for a specific transaction. Will use nanoid if installed, uses + uuid.uuid4 otherwise. Logging also supports a trace_reason log token + with the url for a web request. The logging format can be changed in + config.ini. (John Rouillard) - issue2551152 - added basic PGP setup/use info to admin_guide. (John Rouillard)
--- a/doc/admin_guide.txt Sun Dec 07 17:33:25 2025 -0500 +++ b/doc/admin_guide.txt Mon Dec 08 23:05:26 2025 -0500 @@ -239,8 +239,8 @@ ~~~~~~~~~~~~~~~~ The trace_id provides a unique token (a UUID4 encoded to make it -shorter) for each transaction in the database. It is unique to -each thread or transaction. A transaction: +shorter or a nanoid) for each transaction in the database. It is +unique to each thread or transaction. A transaction: for the web interface is each web, rest or xmlrpc request @@ -282,6 +282,9 @@ for thing in things: process_one(thing) +You can change the format of the trace_id if required using the +tracker's interfaces.py file. See the :ref:`module docs for the +logcontext module <logcontext_pydoc>` for details. Advanced Logging Setup ----------------------
--- a/doc/installation.txt Sun Dec 07 17:33:25 2025 -0500 +++ b/doc/installation.txt Mon Dec 08 23:05:26 2025 -0500 @@ -253,6 +253,10 @@ version 2.0 of gpg from test.pypi.org. See the `gpg install directions in the upgrading document`_. +nanoid + If nanoid_ is installed, it is used to generate short unique + ids to link all logging to a single request. If not installed, + uuid4's from the standard library are used. jinja2 To use the jinja2 template (may still be experimental, check out @@ -2432,6 +2436,7 @@ .. _mod_python: https://github.com/grisha/mod_python .. _mod_wsgi: https://pypi.org/project/mod-wsgi/ .. _MySQLdb: https://pypi.org/project/mysqlclient/ +.. _nanoid: https://pypi.org/project/nanoid/ .. _Olson tz database: https://www.iana.org/time-zones .. _polib: https://polib.readthedocs.io .. _Psycopg2: https://www.psycopg.org/
--- a/doc/pydoc.txt Sun Dec 07 17:33:25 2025 -0500 +++ b/doc/pydoc.txt Mon Dec 08 23:05:26 2025 -0500 @@ -1,10 +1,14 @@ -================ -Pydocs from code -================ +================================ +Embedded documentation from code +================================ .. contents:: :local: +The following are embedded documentation selected from the Roundup +code base. You can see the same information using the ``help`` +function after importing the modules. + Client class ============ @@ -40,3 +44,11 @@ .. autoclass:: roundup.cgi.templating::TemplatingUtils :members: + +Logcontext Module +================= +.. _logcontext_pydoc: + +.. automodule:: roundup.logcontext + :members: + :exclude-members: SimpleSentinel
--- a/roundup/admin.py Sun Dec 07 17:33:25 2025 -0500 +++ b/roundup/admin.py Mon Dec 08 23:05:26 2025 -0500 @@ -49,7 +49,7 @@ ) from roundup.exceptions import UsageError from roundup.i18n import _, get_translation -from roundup.logcontext import gen_trace_id, store_trace_reason +from roundup.logcontext import gen_trace_id, set_processName, store_trace_reason try: from UserDict import UserDict @@ -2355,6 +2355,7 @@ print(function.__doc__) return 1 + @set_processName("roundup-admin") @gen_trace_id() @store_trace_reason('admin') def run_command(self, args):
--- a/roundup/cgi/wsgi_handler.py Sun Dec 07 17:33:25 2025 -0500 +++ b/roundup/cgi/wsgi_handler.py Mon Dec 08 23:05:26 2025 -0500 @@ -13,7 +13,7 @@ from roundup.anypy.strings import s2b from roundup.cgi import TranslationService from roundup.cgi.client import BinaryFieldStorage -from roundup.logcontext import gen_trace_id, store_trace_reason +from roundup.logcontext import gen_trace_id, set_processName, store_trace_reason BaseHTTPRequestHandler = http_.server.BaseHTTPRequestHandler DEFAULT_ERROR_MESSAGE = http_.server.DEFAULT_ERROR_MESSAGE @@ -107,6 +107,7 @@ "cache_tracker" not in self.feature_flags or self.feature_flags["cache_tracker"] is not False) + @set_processName("wsgi_handler") @gen_trace_id() @store_trace_reason("wsgi") def __call__(self, environ, start_response):
--- a/roundup/configuration.py Sun Dec 07 17:33:25 2025 -0500 +++ b/roundup/configuration.py Mon Dec 08 23:05:26 2025 -0500 @@ -2440,6 +2440,12 @@ for name, value in get_context_info(): if not hasattr(record, name): setattr(record, name, value) + continue + if (name == "processName" and + isinstance(value, str) and + getattr(record, name) == "MainProcess"): + setattr(record, name, value) + record.pct_char = "%" record.ROUNDUP_CONTEXT_FILTER_CALLED = True
--- a/roundup/logcontext.py Sun Dec 07 17:33:25 2025 -0500 +++ b/roundup/logcontext.py Mon Dec 08 23:05:26 2025 -0500 @@ -1,9 +1,70 @@ +"""Generate and store thread local logging context including unique +trace id for request, request source etc. to be logged. + +Trace id generator can use nanoid or uuid.uuid4 stdlib function. +Nanoid is preferred if nanoid is installed using pip as nanoid is +faster and generates a shorter id. If nanoid is installed in the +tracker's lib subdirectory, it must be enabled using the tracker's +interfaces.py by adding:: + + # if nanoid is installed in tracker's lib directory or + # if you want to change the length of the nanoid from 12 + # to 14 chars use: + from functools import partial + from nanoid import generate + import roundup.logcontext + # change 14 to 12 to get the default nanoid size. + roundup.logcontext.idgen=partial(generate, size=14) + + # to force use of shortened uuid when nanoid is + # loaded by default + import roundup.logcontext + roundup.logcontext.idgen=roundup.logcontext.short_uuid + +""" import contextvars import functools import logging import os import uuid + +def short_uuid(): + """Encode a UUID integer in a shorter form for display. + + A uuid is long. Make a shorter version that takes less room + in a log line and is easier to store. + """ + alphabet = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz1234567890" + result = "" + alphabet_len = len(alphabet) + uuid_int = uuid.uuid4().int + while uuid_int: + uuid_int, t = divmod(uuid_int, alphabet_len) + result += alphabet[t] + return result or "0" + + +try: + from nanoid import generate + # With size=12 and the normal alphabet, it take ~4 months + # with 1000 nanoid's/sec to generate a collision with 1% + # probability. That's 100 users sec continously. These id's + # are used to link logging messages/traces that are all done + # in a few seconds. Collisions ae unlikely to happen in the + # same time period leading to confusion. + # + # nanoid is faster than shortened uuids. + # 1,000,000 generate(size=12) timeit.timeit at 25.4 seconds + # 1,000,000 generate(size=21) timeit.timeit at 33.7 seconds + + #: Variable used for setting the id generator. + idgen = functools.partial(generate, size=12) +except ImportError: + # 1,000,000 of short_uuid() timeit.timeit at 54.1 seconds + idgen = short_uuid #: :meta hide-value: + + logger = logging.getLogger("roundup.logcontext") @@ -46,6 +107,11 @@ # set up sentinel values that will print a suitable error value # and the context vars they are associated with. +_SENTINEL_PROCESSNAME = SimpleSentinel("processName", None) +ctx_vars['processName'] = contextvars.ContextVar("processName", + default=_SENTINEL_PROCESSNAME) + + _SENTINEL_ID = SimpleSentinel("trace_id", "not set") ctx_vars['trace_id'] = contextvars.ContextVar("trace_id", default=_SENTINEL_ID) @@ -55,23 +121,8 @@ default=_SENTINEL_REASON) -def shorten_int_uuid(uuid): - """Encode a UUID integer in a shorter form for display. - - A uuid is long. Make a shorter version that takes less room - in a log line. - """ - - alphabet = "ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz1234567890" - result = "" - while uuid: - uuid, t = divmod(uuid, len(alphabet)) - result += alphabet[t] - return result or "0" - - def gen_trace_id(): - """Decorator to generate a trace id (encoded uuid4) and add to contextvar + """Decorator to generate a trace id (nanoid or encoded uuid4) as contextvar The logging routine uses this to label every log line. All logs with the same trace_id should be generated from a @@ -84,15 +135,22 @@ used by a different invocation method. It will not set a trace_id if one is already assigned. - A uuid4() is used as the uuid, but to shorten the log line, - the uuid4 integer is encoded into a 62 character ascii - alphabet (A-Za-z0-9). + If a uuid4() is used as the id, the uuid4 integer is encoded + into a 62 character alphabet (A-Za-z0-9) to shorten + the log line. This decorator may produce duplicate (colliding) trace_id's when used with multiple processes on some platforms where uuid.uuid4().is_safe is unknown. Probability of a collision is unknown. + If nanoid is used to generate the id, it is 12 chars long and + uses a 64 char ascii alphabet, the 62 above with '_' and '-'. + The shorter nanoid has < 1% chance of collision in ~4 months + when generating 1000 id's per second. + + See the help text for the module to change how the id is + generated. """ def decorator(func): @functools.wraps(func) @@ -100,7 +158,7 @@ prev = None trace_id = ctx_vars['trace_id'] if trace_id.get() is _SENTINEL_ID: - prev = trace_id.set(shorten_int_uuid(uuid.uuid4().int)) + prev = trace_id.set(idgen()) try: r = func(*args, **kwargs) finally: @@ -111,6 +169,26 @@ return decorator +def set_processName(name): + """Decorator to set the processName used in the LogRecord + """ + def decorator(func): + @functools.wraps(func) + def wrapper(*args, **kwargs): + prev = None + processName = ctx_vars['processName'] + if processName.get() is _SENTINEL_PROCESSNAME: + prev = processName.set(name) + try: + r = func(*args, **kwargs) + finally: + if prev: + processName.reset(prev) + return r + return wrapper + return decorator + + def store_trace_reason(location=None): """Decorator finds and stores a reason trace was started in contextvar. @@ -195,7 +273,7 @@ #Is returning a dict for this info more pythonic? def get_context_dict(): - """Return dict of context var tuples ["var_name": "var_value", ...}""" + """Return dict of context var tuples {"var_name": "var_value", ...}""" return {name: ctx.get() for name, ctx in ctx_vars.items()} # Dummy no=op implementation of this module:
