From 978a86681300c4e4bc725b9223bc6ffe2bfacf3a Mon Sep 17 00:00:00 2001 From: HotSwapp <47397945+HotSwapp@users.noreply.github.com> Date: Mon, 6 Oct 2025 23:00:25 -0500 Subject: [PATCH] chore: route uvicorn logs to structlog; disable default access logs --- Dockerfile | 2 +- .../logging_config.cpython-313.pyc | Bin 2543 -> 5707 bytes app/logging_config.py | 73 +++++++++++++++++- app/uvicorn_log_config.json | 38 +++++++++ 4 files changed, 108 insertions(+), 5 deletions(-) create mode 100644 app/uvicorn_log_config.json diff --git a/Dockerfile b/Dockerfile index d95641c..8a58c15 100644 --- a/Dockerfile +++ b/Dockerfile @@ -31,4 +31,4 @@ HEALTHCHECK --interval=30s --timeout=30s --start-period=5s --retries=3 \ CMD curl -f http://localhost:8000/health || exit 1 # Run the application -CMD ["python", "-m", "uvicorn", "app.main:app", "--host", "0.0.0.0", "--port", "8000"] \ No newline at end of file +CMD ["python", "-m", "uvicorn", "app.main:app", "--host", "0.0.0.0", "--port", "8000", "--no-access-log", "--log-config", "app/uvicorn_log_config.json"] \ No newline at end of file diff --git a/app/__pycache__/logging_config.cpython-313.pyc b/app/__pycache__/logging_config.cpython-313.pyc index 45d1acbf3f349ed7b33767cb1f50a0f384db2167..e73c43611cde58f61936ee94718a16de428d4b11 100644 GIT binary patch literal 5707 zcmd5=O>Y~=8QvwA)RJ84gVDESdu3U&7|Uc}SxJ@JDV#V;Y$r-UnhpZRSggnuxemF@ z%q;CnC!Y%6dTCl8dT@aPNiJ=UDbQnofL2no>Q-nAB$wWl*hPR|+V`FPAk8q9j~$7# z^F2E=&-*;@?BjGg$wBz?=U>+j20894%mg9oCHTh=An`F*?z!cU5}Ia^*++)*Na3fCX2C2?v6kb#Z)oQQpuuJ>|?1^FSORkm70tH^b;TGfrJTsDnOz1kwGrJIJlX%gA0Y4TOA z-mK~JRn<~ARI16VDz&b>drelG&0I2hv!+wIVOCmoE$pvRnX=JgVA(Qdvt>0~mVCYV z&Kk}|W!0$2x?yQmm`bBbnAg&NYRPw1qN^Kq>~6|L`>3T+>pX30WqngG%bU7ZuTXhG z%T;rWLA9b+va(9Fq;8b!tqLqgZCPdmR!~;!^(~kMXN1;elT>If`A^)HEbpdN!!Rwj zP`Z|lxX~-dmMdJ<%U0PxGPZpJ#E|D7{|yo!bEQauXXQ^tc%aJ>uSou(HqmEjBRoT! z*fX?=KSP_or`w$2vf}ogYn(MKzMsD{iXdLsV%{ILai|tctd&w(3?k>hg*kQ4}``Z)sRc z1rC(rfy%P%UeA|c1e&jz7QLr7^Hys2T)e3O`WG-#QxFsz@i_*g%G_d*_Ep7#v| z-UAIJ*W7YP6}3`Pa1FReia$Rk129(xe)JAR_qij9iw!u!ge^=wT>Mnn7tS9D{eJ%Z zr^EX~uAM*k$l4bc+xhPL?4z6e!t>v&PmSydBadM=u8dI-L`X2?{sR&pbL&AlSMZS< z7C@qaIPVG_J>p$ekS*Z&U16QkAQpD?mAV>1wt$<|70`x?(Ur(CJ%L`kLp}!B6}B(F zW;PmtPB_Z4Mk#Ptxu$~k184xkkfm0ou5U2hZVF9@2ZAqK-ywOac_7xjj#Z?D0Ki}ox#CPhVMk()J>SH zh;wPg9YA<07E#OEhFboRe#Q}8AnAw59alD5dcC5+yK8#YP?`j0#3d0Ks%PLw--GBr z_ax3GGLCq{7Ed^0-WKzR;*cYb+v2z*&fDVrp?H#&OxxnLBQDtD!l$J#Qaj?pj(D}B zV$l{Ck5X|de#FINarPqRPO^)^WDHQhgVJLGg{`|n$I|KKS2)fPj+><<1ig$Hnfwq@vEyca`^OxY;$*HWWMkWQ0Yq2} zj9>u;xOG5>+H@t47RLwbs_|vs8XJFsD_MfT~)+z`o{dOe$zFjI0p?Rt95v z@~#@7457(E8OVy(&|w6SXv%zn#UzYauA%3Fenx0)fxo~^cVmlH0t?qc(wSp|YLH8U zttLXla)-WWCZGj<{t~y-ej>+Sa=Smss%7Mg)wOJz;1Lq^o!rd#*G#6dLP7_opcxg7 zz&J7%_4&%+ri)De-h_>wVZ zFrr5uZUWZi?YZ0McXLz3G%X|;I5Af+)Q09JT6g^digpD`2f^bIS@BLu@lFCb#3x7A z0XCkXK`p|M{sAK35{Vm{bOvR6P<95F?7^kO%#@Rvw=?rjX35Sh?PZn^Cok+xUOb9% zLl=*@=urIrwI@k#VAScK-R+;<>z}*-#(|J>gmGIKe>kx(%mO_ zC|h02oIzm z`aOjnl61PWzK6e42qge!_d~~sAyo%;;Q92Bsg54K=IG(^tcL>C(Ra8#OOWa%5a?wU z1@N=lEAQ2FJQ$<>?C8X%tGAKG`#F?O7`x(gpF+CBzU7;8&##dr+ zp-y_2W`i&BaK2%y!kI7`CfcGOi1LD8SIMFCaD4xw81xLD;Rt|^bu=XwI-P}T0{^n9 z?cXOoCcq0>XiUtN4KC8`(tc03YMllz(^j)-5{vNx^K`YONB@Dnw*}wy?&RM69EAM} zsnVB|s2`yUy)3`28+xPFz#^G>wd@@_1sQ7KY7JMhnCJB(KFM%BDw&Zu%a9L7~8_o+ztuSM-%lF%4x?C)84aIG=J$5sNSt|M-`XfEzkj zfM<8`-7kI}IKm6-p@UlD;qJjL`!(w!5A?d>^s@Ni<{zFcFwooJ?1AGIVeVHnE3AgK_v zXf*?E&t0mU@DYT*lKY_!AHk?T6(0&PCdACI56?+vyWyTt$%)IZ}O!-PB<&q z?3HWI$_Mt!2hPCly@A_*8Jqeh#${%X;@sef$NzIM&{|d?SKztL&J}N0Z+TuyoWNTV z!xc76vz{F$xKVBjJ|*d858!O&Zo*R_K)dIL4Q%Rla5t5WE&ncsoJ1xtn!*S#k)9%* zz!b6yQzS~ zFYeC0xHtDBM_RGr|8i;n)@|ojb@x_vr}oj_E#h3J_GNkqSICJ!i%UmQ?iGvQkyaQA zvLZnlCa5d~#m|ibZILvj{@s5S_J19+i!yv@yG>rlHt#|NyNzjAsKW;$KoD*{+{)p@ zl2^QD8k*l`dkF0TfwdYq6xji{Pf;pn8Nc`_%4Q3{XDSLoWA<^fE+8QJ&|&iNtx~UxOS! z`xV#!S8n9*-1Jx6;FGw-k3Kmm^6@95k_r34U``&x=W#(rzauyDU06V>{ z;)=K|5os9_WB?0V!ir2}OSYt8uql$jLxFykV*|IK6|fMeHX#XB z1v9w!@sR-g>45lDgIxCF@D>69@a%w|q6xYeehpQ6qc2M50@0qeIDHeD{0lXjii~k+ ztPTAu{_isvFpVAzpO@d4VsMPE_f5hCeH+%a%tcd6vd|sL09DxxJbOXc)dl)l%_V)I z<~n}Rt2MCe6&p>n#}_IM&lk4v_B~VbLrvn8vFkd-rC0lN>Ab1>a^0y`Yj)M|Efw8b z`L1JEYE?hzdZbnMSk4cYx{^jOMDL}x?N8I(|bW!YNIuVH%w6S^B6oE>Qtw{W3S zt9zI*#X`wx*&79}kBJHWAVY;ZeuC>RUxWULYW+zD40hf3%)A0!l?Gy?^k!^v@lc6( z6r-&e9VOLPQu|8!BrL~5T@~mfhq}?xr`!5;N6)nN%)UN%sEv2D`ET0%r`*1_bZ~j< zY$z-tD#Wi(`G{bzMQoB{EliPIV~%~4?U7lI#Jpo;vzI=PkGve^1oF0 diff --git a/app/logging_config.py b/app/logging_config.py index bd1fa61..90c8cbe 100644 --- a/app/logging_config.py +++ b/app/logging_config.py @@ -9,6 +9,7 @@ included automatically in log records. from __future__ import annotations import logging +import logging.config from typing import Any, Dict import structlog @@ -29,29 +30,93 @@ def _add_required_defaults(_: Any, __: str, event_dict: Dict[str, Any]) -> Dict[ return event_dict +def _build_foreign_pre_chain() -> list: + """Common processor chain used for stdlib log bridging.""" + return [ + structlog.contextvars.merge_contextvars, + structlog.stdlib.add_log_level, + _add_required_defaults, + structlog.processors.TimeStamper(fmt="iso", key="timestamp"), + structlog.processors.dict_tracebacks, + ] + + +def _ensure_stdlib_processor_logging(log_level: int) -> None: + """Route stdlib (and uvicorn) loggers through structlog's ProcessorFormatter. + + This ensures uvicorn error logs and any stdlib logs are emitted as JSON, + matching the structlog output used by the application code. + """ + formatter = structlog.stdlib.ProcessorFormatter( + processor=structlog.processors.JSONRenderer(), + foreign_pre_chain=_build_foreign_pre_chain(), + ) + + handler = logging.StreamHandler() + handler.setFormatter(formatter) + + # Root logger + root_logger = logging.getLogger() + root_logger.handlers = [handler] + root_logger.setLevel(log_level) + + # Uvicorn loggers (error/access/parent) + for name in ("uvicorn", "uvicorn.error", "uvicorn.access"): + uv_logger = logging.getLogger(name) + uv_logger.handlers = [handler] + uv_logger.propagate = False + uv_logger.setLevel(log_level) + + +def build_uvicorn_structlog_formatter() -> logging.Formatter: + """ + Factory used by logging.config.dictConfig to create a ProcessorFormatter + that renders JSON and merges contextvars. This is referenced by + app/uvicorn_log_config.json. + """ + return structlog.stdlib.ProcessorFormatter( + processor=structlog.processors.JSONRenderer(), + foreign_pre_chain=_build_foreign_pre_chain(), + ) + + def setup_logging(log_level: int = logging.INFO) -> None: """ - Configure structlog for JSON logging with contextvars support. + Configure structlog for JSON logging with contextvars support and bridge + stdlib/uvicorn loggers to JSON output. Args: log_level: Minimum log level for application logs. """ - # Configure stdlib logging basic config for third-party libs (uvicorn, etc.) + # Do not clobber handlers if already configured by a log-config (e.g., uvicorn --log-config) + # basicConfig is a no-op if handlers exist. logging.basicConfig(level=log_level) structlog.configure( processors=[ + structlog.stdlib.filter_by_level, structlog.contextvars.merge_contextvars, structlog.stdlib.add_log_level, _add_required_defaults, structlog.processors.TimeStamper(fmt="iso", key="timestamp"), structlog.processors.dict_tracebacks, - structlog.processors.JSONRenderer(), + # Defer rendering to logging's ProcessorFormatter to avoid double JSON + structlog.stdlib.ProcessorFormatter.wrap_for_formatter, ], context_class=dict, logger_factory=structlog.stdlib.LoggerFactory(), - wrapper_class=structlog.make_filtering_bound_logger(log_level), + wrapper_class=structlog.stdlib.BoundLogger, cache_logger_on_first_use=True, ) + # If uvicorn/root handlers are not already using ProcessorFormatter, ensure they do. + def _has_processor_formatter(logger: logging.Logger) -> bool: + for h in logger.handlers: + if isinstance(getattr(h, "formatter", None), structlog.stdlib.ProcessorFormatter): + return True + return False + + if not (_has_processor_formatter(logging.getLogger()) or _has_processor_formatter(logging.getLogger("uvicorn"))): + _ensure_stdlib_processor_logging(log_level) + diff --git a/app/uvicorn_log_config.json b/app/uvicorn_log_config.json new file mode 100644 index 0000000..9afb3a0 --- /dev/null +++ b/app/uvicorn_log_config.json @@ -0,0 +1,38 @@ +{ + "version": 1, + "disable_existing_loggers": false, + "formatters": { + "structlog": { + "()": "app.logging_config.build_uvicorn_structlog_formatter" + } + }, + "handlers": { + "default": { + "class": "logging.StreamHandler", + "formatter": "structlog" + } + }, + "loggers": { + "": { + "handlers": ["default"], + "level": "INFO" + }, + "uvicorn": { + "handlers": ["default"], + "level": "INFO", + "propagate": false + }, + "uvicorn.error": { + "handlers": ["default"], + "level": "INFO", + "propagate": false + }, + "uvicorn.access": { + "handlers": ["default"], + "level": "INFO", + "propagate": false + } + } +} + +