From 048383517e4152f3b0915a9d2f939a3c27872de6 Mon Sep 17 00:00:00 2001 From: yahiaongh Date: Thu, 23 Jul 2026 11:25:18 +0100 Subject: [PATCH] fix: derive log level from status_code instead of independent randomization (root cause of inflated error-rate metrics); tune anomaly burst probability (partial fix, documented as still-open) --- docs/MILESTONES.md | 3 ++- infra/docker-compose.yml | 3 +++ .../__pycache__/producer.cpython-312.pyc | Bin 0 -> 8783 bytes services/log-producer/producer.py | 23 +++++++++++++----- 4 files changed, 22 insertions(+), 7 deletions(-) create mode 100644 services/log-producer/__pycache__/producer.cpython-312.pyc diff --git a/docs/MILESTONES.md b/docs/MILESTONES.md index 88e4e87..3a7f11e 100644 --- a/docs/MILESTONES.md +++ b/docs/MILESTONES.md @@ -49,7 +49,8 @@ Status and scope for each phase of SentinelOps. Dates are approximate; this is a ## Known gaps (tracked, not blocking) - No Grafana/Prometheus scrape config yet — metrics are exposed but not yet centrally collected -- Sustained 40-49% error rates across all services for over an hour post-recovery (not resolving over time as event counts grew 10x) — this looks like a real bug (possibly in the `/api/services` error-rate calculation, or an actual issue in the log producer/ingestion path) rather than a transient catch-up artifact. Needs investigation as the next priority after Milestone 4. +- Fixed: log producer was assigning `level` independently of `status_code` (a 200 response could randomly be logged as ERROR) — root cause of inflated error-rate metrics. Fixed by deriving level from status_code. +- Still open: even after that fix, ANOMALY_PROBABILITY (tuned 0.02 → 0.0015 based on burst-duration math) has not brought error rates down to the expected ~5% in live testing — actual observed rates remain 25-37%. The duty-cycle calculation may be missing a factor (e.g. multiple concurrent bursts per service, or burst state not resetting as assumed). Needs a fresh look with the producer's actual runtime behavior, not just the math. ## Recently closed - `anomaly-rust`: added `detect()` end-to-end tests, including a regression guard for the directional-severity bug diff --git a/infra/docker-compose.yml b/infra/docker-compose.yml index 3ef8778..c34cc4b 100644 --- a/infra/docker-compose.yml +++ b/infra/docker-compose.yml @@ -31,6 +31,9 @@ services: depends_on: [redpanda] environment: KAFKA_BROKERS: redpanda:9092 + LOG_TOPIC: service-logs + EMIT_INTERVAL_SECONDS: "0.2" + ANOMALY_PROBABILITY: "0.0015" ports: - "8080:8080" networks: [sentinelops-net] diff --git a/services/log-producer/__pycache__/producer.cpython-312.pyc b/services/log-producer/__pycache__/producer.cpython-312.pyc new file mode 100644 index 0000000000000000000000000000000000000000..f39309688a782f7dcff27f5595aef1ca44e73c15 GIT binary patch literal 8783 zcmd5hTTmNUmfcdf)OsKZ0pekU+fR_g%a4hlvBwX<_#r!nI2%noDp}otKo912%QhO} z!Ih)}Q&VNwWD8t&)>LY$mQ3G2OzR29j3;c^?p$MLt@WnH(z_sZMB4n zlS%E@Uc`O%x%ZxX&*PqR?mw55*cnJ)d>!t8v5H~-9UDfnInS#|n3gwnO1*jT;+VrE4rIOcx zEUdoyCr6Y?Yissetvr@%(s<^X3uN{V3Tvn8DFLcAAJcZIMJ+RHNnsx#?ng;U()Jo2sXg_x% zbn^1Wb8VNq(ymw%4!19hg8sn!SGNV*h|rD(ZqGAB*~E9oVK+@!bEKeOH$gUSB-ILr`{%V9L@zmEiHgi zGy!l#?jf?$*Q6!~%JeVt^gc19+7RdW!-ZLoJjXRG_Y_4Ww~_n-P@irRKpQ;)BU(wg)Q8 z0m$BB9=S^2xR7&u-w5PNJa3%O(Wb-o#@SqHd6p~Bc`CA8#kxGyKAvy=W zn4YvlRwTN_!bNKW1qP6I4*$Qndw1suw1!&ubc)v|^o}fBxs0&U? zPPcW#=?^I4jXoJvA`x%M^`NjKDMH{VKn2F5Qd6ERO;opuAmn0L?2Q5wi1{;Wj^yuP ziZ0%%$gfYl6zwRJVM6o+W<$&eY~TY{D+z;=xh{uveF-XvQ{-5Wg7b(3Z)+rcG!a!p zp>)N1jGK+_lK`Zk)iT25np#G=FNFL#R^w<3k>P$w1S0tx9{L!@3jY+d6{t)y88*Z8 zWB-P9oh83k5ss$*^)uxAj5|y7ub!dOtO~}! zew3pPNit{HdyK?oOpx>M@rIQEcPjn!TLP=)FlH6SH@)jud37mv2F|vf>TWxIRRro2 zVD(=8!V;4Su|937r^HQLMJnNn-$KyZfwP1gG8rcxY*?{@l4Sw8=#`0Py%8n}n8|M@ zC!9>{>q4)4^C<(kF? z_&FLs^?g?RaqTBtmQGz++;e56s_ud7u4|gi?9Em+k9OvE?;Ab6?5taG)=k}5aMrIl zy>|j*ft>f?T;-hYq3?6s!{5$der?_p{Hxhi;##vZdtYVe9gS2JpJ5s#KV_OasQd)e zFkK931`yH$*$1ZLVJJ9*aR5Rzk>B^TTy1n;09d6AGT5%$XKZ)g-8e5i2RCFtirY9; zehN2o@W+_#rs<{$NhY!BN`{G;BlHUSF=z^D8mNJ7x_%7iC4&jgfmM`eg8QeZLXJW0 znd7iVKv$>Ya=QE(F39&@LhzR%qqHBFmVFHi@N+ceoF0R=S!eyso&{$klsR|VvU}@- zd+T)lf_wK&c+uUGE3aBE-?dP_Yx>4QdCQua@wBe-jMGoa?6(sUCMR1l+Xk6t4S{tO z35CdB?AneQN)V~X>^Np8F+(3i*V(A42)Ye4LkQ&*WN$KGau>hlSiW`5V&PpgWorx+ zv*k~)So5%a)3kYwfntVxg2kGJ<6EbcH3o`l^(hwm{B&w6Q6+gTjIyK3WFM^Z44XQk zgR;V(fGLm_`q%4Z_=qXP6g34vApC|@gcvrdyz#OBIohnKp)w3&Xv{opRtp+SEh)_4 zGHS)r(4vKrpwGrx;seY|i%>?bh#AZLG-lxGu_O(R>?XnNJ7SZk9p5DY)kaR>^3_4@t-}rT`G8<>t|nw({s)ncI8~R zE2~rjc(@99?E2ZOyCsXUqxGvx9@rbsSvqV}K^5rf|4K_0S%Rj1P!=1Ly4mP4sMNp3 z=qZ*4e`J`9IU{7O8B4~N;Uw=zWgp_b52=e;w`&w*nxyh|Cy8>sAxRaI&o}|2Tz?Yl zMx%n=kPNJ(%7N1$_a@1b@U0v19Lh-!sjAmx>~z?gu}akguftd~o_E3yZAZQhyp=FX zHN!%Nft!63Qdion?l4g3cN?{0S-=Op@){WR9{>NGes$~V=id_Wn>B0RG0-g3i&nrq z1kWv$_n#Hg4%>~cfI5l}0%xw`g|hlNWE%JCiOYd>X;&!W5N;D0jTzE`AgINo z|y!lU=)K9)Gh3Wdj;i(Kp;&whX{%Q^@qqNtReT4TFh`2 zf~>!ax_0#@W_Y{w&egs3pD)k-Uu8rR~&QOMwwCuA;fv z?l04?D|%BMz%iCcUlL*;nyoEx`qD*krn~5^rg5nhI9xpD`{|vg@gxaet7c6lqUgr! z&J8lNW=G4ur&0pjJGXi20^XiN%GOO%8G>Q#jF0O`RP;7XUd?F-!Y>5e6?G3VaA z?B2QH-Z|ZybvKWkdF-yZGdwnY|24StYg@AJ){!$SZtuJMCl5~?e&=Y`EsmV|+Um{; z70W{Hf>1lvyCm#dsn|4mb>iyc_Reg@*-?AWQ887$=-9SWU3dTbgIjlR%}BGSvs(_$ z?a5ZZG2A}X+}WCgIC>L~Zk?@~wa@#GjCDLNEcMK&{89+)>lp1=aaXQXRNXIsP;Slu$Q{nIO- zUH$m#!&9G^Jv^NKMPTGy&gvbHELy8`p2{&kXDgpFFWNTcJiamhk;ga6=Sr)_ZBy0L z2d8(>oc&b&Ed6o%lgz`D4_}@?&@unwnR!>|NXLq!Y^AjP-R{ZYMDU&0v!&Zsyfu@J z6OH$ktatmew`sxKl=Zg20=d%aoU1HXz9m;yn{QUv!Csse*b8s@p~;SHOKl-gvSh)6?^;9*G5;qhReAkYLl~tDuF!TLaz78CqQTwEX5kdedn+2A(V#$}0vclthjs z35claun2z9A(%$vsfN+a1M(2Y>7WHdr1U;x4!foNTp=P4CW%UVVdNzID`*G;<6G?` zzgrPpcbsF+`O3Ys`#wAH@qtec&Au>q`Js6(HDA&8h0qRGu288T3JfYF8`S8bq#=LX zGRdf*S@fi$LZt~^)ceJ&iYYp{r$=|Ic6-r1IfVQ$Pq7S##^z8_;k8&dHM4dxkUi{=poAxs&T8qj$v4D;Yw zp@!U$idX@&qTbw)q{35(S}>;i#SK8vRJR*_nL^;e!0d0#TQEdEvVX|wv#=mu{pcTU zNRnX82@ss*NF P;;h1JSBme%+=~oQ=%lp!I`_>GZ*JlF;+&?^B#3nloOhYBY;Be z9~J>ibj&v-$z6o|8@PB7m-h;?0o;h;4x0MW(AbdH?|%rShK2uO_6FlG4Wz5q#ThZ! zT?jAwP3cmIRH_iq3=cMAbWJ8o+7^KqhlJW3mAapC`B0kCp?R_&vVUMfq6;`YU&$5s zDw%$78UnK@kZ$hkOR4xOVLUZ}>XJd9NsVGpET#0JF;ob8HaEBXO}aYcqKTd)m~Iw) zp-9Cc&`Kao3*n(u0;56su+NBonY(qHC8XrnO4r82(M0o6`WB!ZYu@nrpI{#f%G7_4 zFpojoImR6G<)@c~Hn`HptW>q7ixDh1zygM1(=jl@2H~ZqKJBVUOYjcx!X6dfzv^*=B!Y<~^2? zGf!R2v3B-fE81u4$9wN*?%i7OHO*JFj|3pgxx6DCPdPJR_0-Prj<+w|zVPm@$)<^> z=`Bm#o)ylX?`fWBo^Dy<_CAK5bGOgUd-s0&i`n|Qx_>Eo_`CTlug-h^Zi##Ck+*E* z+?V#!6>k+z@kb%+^^aOtJe#IErhh%#v9R-K*7MRR|48sG3snn3)rzweERIRnglpFUY^-b=c*nR)XblbhFS?>$W-n|Rny|V|h-Xkj&JJxKBt@Hihj(oU!>XA>YqC&{Pn0E ziU{R@%6~+}Ci+!+RBboZz88+_uSv(q-$N6alTnUCzGh}w_8XIx<>38-b$-RTzG7@& zF(ve8|B7+I?=Ou1FU+?8V0QeOsrxfi`EQJ4y!#8L<`GjiVqIp+7MQY}z4T7wSYys{ z?616;HLVGZebZ>=vaM#pRx@=hYui0ydE}`cH%;0mY*Q`sFC58wj*gV%gwj#d9ov{~ z{DrAoS)qA^|FWufDmr!TLG*5PzTx=8ifmm+w(870Q}Ly5(^Tiw$p@WxJLh*DnY)tR zd^+oEn`g?tb{rfLzV;l~oclD-A+5CS8yjC@8nJ!jVuX@6Zj5ki7RKcG&SYmdtuc^2 zF++0=o8Q$`u&v)Pkgc`8#9F2xXbHv4>$I5bdxEWRe`zwY9qbePZq~CFWEsvmnqD+l Of5{1Nq1~B(%KBfCz{}47 literal 0 HcmV?d00001 diff --git a/services/log-producer/producer.py b/services/log-producer/producer.py index 4ca21f0..01b590a 100644 --- a/services/log-producer/producer.py +++ b/services/log-producer/producer.py @@ -33,8 +33,14 @@ KAFKA_BROKERS = os.getenv("KAFKA_BROKERS", "localhost:9092") TOPIC = os.getenv("LOG_TOPIC", "service-logs") EMIT_INTERVAL_SECONDS = float(os.getenv("EMIT_INTERVAL_SECONDS", "0.2")) -ANOMALY_PROBABILITY = float(os.getenv("ANOMALY_PROBABILITY", "0.02")) - +# Target: anomaly bursts should occupy roughly 3-5% of total time per +# service, not be the dominant traffic pattern. With burst length averaging +# ~40 events (random.randint(20, 60)) and ~1.25 events/sec/service, a 0.02 +# probability produced bursts ~44% of the time — anomalies were effectively +# "normal," which defeats statistical anomaly detection entirely (there's no +# stable low baseline to detect deviation from). 0.0015 targets ~5% duty cycle: +# mean gap = 1/0.0015 ≈ 667 events, duty = 40/(667+40) ≈ 5.7%. +ANOMALY_PROBABILITY = float(os.getenv("ANOMALY_PROBABILITY", "0.0015")) SERVICES = ["checkout", "auth", "payments", "inventory"] ENDPOINTS = { "checkout": ["/cart/add", "/cart/checkout", "/cart/remove"], @@ -42,7 +48,6 @@ "payments": ["/charge", "/refund", "/payment-status"], "inventory": ["/stock/check", "/stock/reserve", "/stock/release"], } -LOG_LEVELS = ["INFO", "INFO", "INFO", "WARN", "ERROR"] fake = Faker() @@ -123,12 +128,18 @@ def build_event(service: str, anomaly_state: AnomalyState) -> LogEvent: anomaly_injected=True, ) - # Normal baseline traffic + # Normal baseline traffic. `level` is derived from `status_code` (not + # independently randomized) so downstream error-rate calculations are + # meaningful: a 200 response must never be logged as ERROR, and vice versa. latency_ms = round(max(5, random.gauss(120, 40)), 2) status_code = 200 if random.random() > 0.03 else random.choice([400, 404]) - level = random.choice(LOG_LEVELS) + if status_code >= 500: + level = "ERROR" + elif status_code >= 400: + level = "WARN" + else: + level = "INFO" message = f"{service} handled {endpoint} for user {fake.uuid4()[:8]}" - return LogEvent( event_id=str(uuid.uuid4()), timestamp=datetime.now(UTC).isoformat(),