From 678a888067e890092b75be56bff563d1534a2c13 Mon Sep 17 00:00:00 2001 From: "Marc M. Adkins" Date: Tue, 11 Feb 2025 18:08:41 -0800 Subject: [PATCH 01/10] Add indentation by depth --- example/main.go | 22 +++++++++++++++--- handler.go | 61 ++++++++++++++++++++++++++++++++++++++++++++++++- 2 files changed, 79 insertions(+), 4 deletions(-) diff --git a/example/main.go b/example/main.go index ca78958..b101120 100644 --- a/example/main.go +++ b/example/main.go @@ -8,10 +8,11 @@ import ( "github.com/phsym/console-slog" ) +var hdlr *console.Handler + func main() { - logger := slog.New( - console.NewHandler(os.Stderr, &console.HandlerOptions{Level: slog.LevelDebug, AddSource: true}), - ) + hdlr = console.NewHandler(os.Stderr, &console.HandlerOptions{Level: slog.LevelDebug, AddSource: true}) + logger := slog.New(hdlr) slog.SetDefault(logger) slog.Info("Hello world!", "foo", "bar") slog.Debug("Debug message") @@ -23,4 +24,19 @@ func main() { With("bar", "baz") logger.Info("group info", "attr", "value") + + hdlr.SetIndentation("", " ") + slog.Info("factorial", "result", factorial(4)) +} + +func factorial(number uint) uint { + hdlr.Increment() + defer hdlr.Decrement() + + slog.Info("factorial", "number", number) + + if number < 2 { + return 1 + } + return number * factorial(number-1) } diff --git a/handler.go b/handler.go index 82ce3ea..a8d5d11 100644 --- a/handler.go +++ b/handler.go @@ -40,12 +40,52 @@ type HandlerOptions struct { Theme Theme } +type Indenter interface { + SetIndentation(prefix, indent string) + Increment() + Decrement() +} + +// indentation defines support data for enhanced message and arg indentation by depth. +type indentation struct { + // Prefix for indentation string. + prefix string + + // Indent string for each depth level. + indent string + + // Depth is the current indentation depth + depth uint +} + +func (hd *indentation) indentMsg(msg string) string { + if hd.prefix == "" && (hd.indent == "" || hd.depth < 1) { + // No indentation. + return msg + } + + // Build indentation string. + builder := strings.Builder{} + if hd.prefix != "" { + builder.WriteString(hd.prefix) + } + if hd.indent != "" && hd.depth > 0 { + var i uint + for i = 0; i < hd.depth; i++ { + builder.WriteString(hd.indent) + } + } + builder.WriteString(msg) + return builder.String() +} + type Handler struct { opts HandlerOptions out io.Writer group string context buffer enc *encoder + indentation } var _ slog.Handler = (*Handler)(nil) @@ -89,7 +129,8 @@ func (h *Handler) Handle(_ context.Context, rec slog.Record) error { if h.opts.AddSource && rec.PC > 0 { h.enc.writeSource(buf, rec.PC, cwd) } - h.enc.writeMessage(buf, rec.Level, rec.Message) + // TODO: Add indentation here. + h.enc.writeMessage(buf, rec.Level, h.indentMsg(rec.Message)) buf.copy(&h.context) rec.Attrs(func(a slog.Attr) bool { h.enc.writeAttr(buf, a, h.group) @@ -135,3 +176,21 @@ func (h *Handler) WithGroup(name string) slog.Handler { enc: h.enc, } } + +var _ Indenter = (*Handler)(nil) + +func (h *Handler) SetIndentation(prefix, indent string) { + h.prefix = prefix + h.indent = indent + h.depth = 0 +} + +func (h *Handler) Increment() { + h.depth++ +} + +func (h *Handler) Decrement() { + if h.depth > 0 { + h.depth-- + } +} From 700f394beeb431f5d66fb53d77997aab4af38e8b Mon Sep 17 00:00:00 2001 From: "Marc M. Adkins" Date: Tue, 11 Feb 2025 19:49:04 -0800 Subject: [PATCH 02/10] Document the new 'feature' --- README.md | 72 ++++++++++++++++++++++++++++++++++- doc/img/factorial-indent.png | Bin 0 -> 10025 bytes example/main.go | 42 -------------------- examples/basic/main.go | 26 +++++++++++++ examples/indent/main.go | 32 ++++++++++++++++ handler.go | 8 ++++ 6 files changed, 137 insertions(+), 43 deletions(-) create mode 100644 doc/img/factorial-indent.png delete mode 100644 example/main.go create mode 100644 examples/basic/main.go create mode 100644 examples/indent/main.go diff --git a/README.md b/README.md index 193e151..cf47cca 100644 --- a/README.md +++ b/README.md @@ -72,4 +72,74 @@ BenchmarkLoggers/dummy-4 1239873 893.2 ns/op BenchmarkLoggers/console-4 483354 2338 ns/op 128 B/op 1 allocs/op BenchmarkLoggers/std-text-4 368828 3141 ns/op 132 B/op 3 allocs/op BenchmarkLoggers/std-json-4 393322 2909 ns/op 248 B/op 4 allocs/op -``` \ No newline at end of file +``` + +## Indentation +`console.Handler` also implements the custom interface: +```go +type Indenter interface { + // SetIndentation configures the prefix and indent strings. + // The prefix, if any, is added first, + // then the indent string is added as many times as the current depth. + SetIndentation(prefix, indent string) + + // Increment the indentation depth. + Increment() + + // Decrement the indentation depth. + // If the current depth is already zero there is no change. + Decrement() +} +``` +Indentation of functions can occasionally be useful for delineating +calls by indenting callees more than callers. + +This isn't something that `log.slog` provides. +It is necessary to provide the handler pointer as a global variable or function +in order to use the `Indenter` interface. + +Because the current `depth` is stored within the `console.Handler` this functionality is not thread-safe. +In order to use it in a multi-thread environment there must be a handler (and logger) for each thread, +and these items must be passed down through all intervening function calls (in lieu of thread variables). + +### Example + +```go +package main + +import ( + "log/slog" + "os" + + "github.com/phsym/console-slog" +) + +var hdlr *console.Handler + +func main() { + hdlr = console.NewHandler(os.Stderr, &console.HandlerOptions{Level: slog.LevelDebug}) + hdlr.SetIndentation("", " ") + slog.SetDefault(slog.New(hdlr)) + slog.Info("factorial", "result", factorial(7)) +} + +func factorial(number uint) uint { + hdlr.Increment() + defer hdlr.Decrement() + + slog.Debug("factorial", "number", number) + var result uint + if number < 2 { + result = 1 + } else { + result = number * factorial(number-1) + } + slog.Debug("factorial", "result", result) + return result +} +``` + +![factorial-indent](./doc/img/factorial-indent.png) + +The specific case of runaway recursion shows up clearly as the messages +march repeatedly across the screen. \ No newline at end of file diff --git a/doc/img/factorial-indent.png b/doc/img/factorial-indent.png new file mode 100644 index 0000000000000000000000000000000000000000..575aea2b237bb12431bd42c974a4478fb07132c5 GIT binary patch literal 10025 zcmbt)cQjlJ+kFtxi85N0(ISFGkCGsI^g6^uWRMUhMDJZj4I`oi(W8XXBBS>a`A{ZQaS&2Y7B!)xl?b(p_O zzixB&$X#%~*luohQ`yYe7w*ERFA~_#0nVWN;2s3lSEN>orB~x3L8M79)-R>Ls-Cdf!Z}-w>wye@-yjjD-FnMct&jZ84QW=p-O88f}sbd519w>1? zk*A?1`5!;B>M#G%f>45=-z6lZ?0cc)BIrSsvtbRdEs>CI*p&960ll8PGxh3KtHfOS zl=pF`c$QEV?An)u3B%OtM`u@~*I$qBF0e8hR7zaAWAl3Dls49Ng_(U3O)GgYIK}Ae ztL2lmzLtR|aI9(D3q7$mI}t;;vxmS_mJ-x0bX3**B*|^XFY!j+yQ3cAxc=c<#ZqCt zT$%6ADPdoF!Lw**MsYbjofE602S&v|Tur70x(|=4X0q7ZiYo@Gq+;W)BC(~jdm7!L z)r^Nkxt4k<*OTsu5}3ACqx;gGDc$U-N&U~53u}g37n+GOed}13cIMMlV4CS9YJD{! zSy2w9hk+`kb)RUB;&~cIseGayVA+~`=M!Oq0wJGAS0~Ta^%wC9%713(Z?96ChVG{2 z_f;M=UDXV?l=spjC|AB#H2$*du=<8T(<>(5?dP?3kfyVTt#m8<1o{R+`;{_3zAYv4 z$H|&cpd|NT#y&?&A9^>w`;HEMz@rzu=OM` z=uc+u-z!0Su9iX-bAn0V{YAj3)}M+GiZB#T-( zqI1iAyD3i{eb=}VPA7R#48vfFVcDl6en0c5lU8-)ZSkHpE2cEGvNt3}PULDUSAx9D z3dQb%^Y5dMN98+(~=t%m{P-s-n zwl11yb$;QidfuyUQm&;<1?P2isUz&vsb%Z;W0_#r)!tU5l+xK&ve&$v1A54QLfV@C z@CO%o+Lzj zKHJMDfP8}_pKFpn?7T-IwWqQ*;S-5n?QnaAPD~XgGV-9>Un6Q$ob>rSV_lzTGH7fa zwWaw(s*S4^i8fp@EruWcBwq-A$J&Ig zWc$0_YhXsQ3hn>${}Do8V~pJKb0_!ru<&e3kW>vceuixpDhUu9_s?s>7h!t=VGop; z7wBpRKW+QHHs#sN6c8S;F6K)sF;Qgl+5RS*R7TWnU*2rsgTgYy`p91gwEea#vg>*( zojin02lAdLY%;wy&lr^tys&gGkG$#f;{8h*p52_F-RW=GE8ggxF~0L$RO0#4EY13~ z1Oo*srMSQLLo$B8hB@lEGwem?0?4W@3Jr|p+CZT5-QWn!Zv zSGqU85W*tNgAC4Xf`$FfmnMs&0^(|iI$M+%_XO9%9bS6O_q|M~i!fM!vsGHGC@NrP zcJxhRfqWxyPUqIksTuJg0oK?;xw4-QjNeww)%F-KgM6p^ROP*PNBt9<@CSn$LN#<= zy1@8Y_3VdSilFj~i2h z5&SU0bs9n*u%^QM&@%SQu@*g;cc`Q&SOJ$Q!{kV^aT#kC%S-SxcR7AEQ3)|aaA zoea<85s555L^;i8wU_CUnhSDq|hwrcM@_v?H#WWFO>VesZ2>v@s{9z~v}>cmPf zbd4{r-(r|rGCiX6>~d4AIPD&@YuosXKv|ks{Iqy0!asJ#i$mJG8H7LXd1DOyo7R|f zC_Jy(oQQ1d`h9#dg@+K6Y!;V z+mn9(xXkA`;p?{nr&GR-!*^tAWJk+U;F)A8R);Wy$H4(&_uA1M?rrxN-L{BRu|8Dc zkM;=$^(?lH*J<7^tSfgLpoFu23oH>2V2#)Nj(EVLmAX<-Bw(%e6iCTs?-4xT7h!mw zZW2F-9b%rETi*x`BjCw{SZqvTCsm#lKOeD7=Q!1rRWEmkd6zt6Jl>UFA|6wIPao5; zLdeqF?QRwG%!RLku7D0qlWjcC2yegy1I-ok{Hw$>9~ zrxZQj@_PG4iFaf2wBfyTc%YpnN z#aWpxrlX3~Pu&P!F>rvV8i~dT$U^Pu8i*be1Y4wVW{$`ltQa276`z8BH`c;j-kUN` zW>7q@dk&+NpU$k=dJ{H6 z@5?8^TgTDj^=Im5j$eP79KTN%>NqaZ3tApRK4vs;q?awooNWB{e$)xmrrRY1j%Vll z(zG1!JRstCcU3d_RT{MCyc>QCEa>6VqkRJFwHk^{4>1><2;Q*YisO=FZ8g3T6 zg~64F<}nY$+Fxw8b-W+(V3n)M1+<$s8HEUZGZJUWfcowLvf{U3tmOR2!r*Apw2`#i zTud5y!{9)e8tL_3ta-$i@dlbxnvfnjHx*$sg_XTN`~q=M%qoO-W%%OhD^c!ibX^~_ zCkhU(8Wz$8E(gpoY%(JM@x+EJ!S(v`%btXki%s6EkYWDYC+71y?Q#EK*}pmN~Iu=@B>Pk6Cn2OCQ#M- z03}Q%=eT|%%yP!Q`}kULrj|6vO8TB7+NVVx)+Pf$rq=p@0q+*By_dxQ06 z$JavTE3X;9o!JX`IPmqRd^N7g1@I8E7bmBKQi}%?TH%^OoT1T5QjT_|05c^-NoG3I z3GaCjeIpo|j>mL{>z%yOE2yCBsJqQ6hh9E!rEoQ$g9Xd+Tocg@a*{vNa90? z(%Qi7(w}qD2V!V?gjhA`0RaO?pRbqv{no#O)<*aUa$@%Z$e@4Y!z{nkg6_0t43yX` z%!F3h&z#bO0!bj+*Ra>`ML)%AF~dwYOs-gg2B_4~%#drsU+JldgkhMyn>x3tv)JBIG^xbHZsmHCcnuzQ+CHYm? zLEx~_QqTZjX#n{aL}^3Mt&vP)Lpp5hl-})y`qH}gtTj+QA)7Lg9<7Ny!kIrSZhn$F zb-I)^RCX<g3vR5cV6B~b7ht%ti|EE4oxY$T7$iCkuquRMXb1*NjgY9Y8ocnU4$1;! z;n+&?rV97(KTbaQEU;^~y!k~TWbI`7!LNto5iwpDq*a%fFz4L`FB0N-aUd}3)Sz_V z@2M`W8JS{=TgRk(L&ss^DVImcHYFfbga55Q{fpvo!j>Zh@E2*SySx|bColqGZ8$a~ zU1zdGPFC`(jOfXPj$3{&{M739`4$JRG%FWsmcIVHJ3Nm>!2f+rYMsyGfq788**x-K z=dAS6mXRD-94;QEwCnX|HEZ|?6$Do%pNA+d9%wUdvr*0?o{zB0Eru*L zZ(QIy*<}C^hTM-6C6)q@McA+)oBJb70w%jog?{~<9`(&Xv0?;vG=QzSV*jd5mi$?{ zm!#s3p1>z~%YJv3m#3EIumcy2GWjdZVN~5(=1nDYS?Xqewm!~6DVr6DfdNyI<^zAN zz>(o?F!eYpj7O%lA^Z25Ony(OE9s@w)Z3`h(D;#hbsV`jl^%gkRhwS7OLA7t@&*Js@)+=!f34^DUj~xWmQ1^EJxY0~h(iO0)^cEl97X{6I2jT#rEZl3z*fUYbJ_wthp_<= z1e%y*CGHPVu?GJsD#4i`VK{DzU9f*uks5#@736S#!|&f3Ul(Y6f8WUO4MAlnqS*r; zES9fe$U(}G9@koGfwB05nuTB}H5Q*H6L2yzVGcF5yRE16$J~@=J129iORPYslmq); zv!ws5;XgyD1zIRYm+>EMuDDA8r3n5steZ%&_MJBivLYS5)3aS&YNazU5N{*oPDFX+ zZ1QOsi9*CiqY(GUZEc$DD>E^+?eUZEt2*@wf$>!A1GNL=5Wau~4=d+kp?F+1!~LJ9 zvmV=J_^p9o@_DnT9r}2_|O)iuy`J+o~RL%-%a?s1cwyKsBJ!p7`XkreCzjS{4Zt_)Ro0& zY$@e^9N8EMM->638bf2=sC~-?%ttu7AA2iNA^m*A z*tdQ$Km6qDsFsCK#nwFmbvLj73v)uiIasMxGLr@xb(FgH2j64Y7|~L7jstwo2_+^h z*#fBJ3HOy882^)yN@ixl9KE#+nt<#EwKm0C=S<&Ey>2AtMQI4gHFW~rMo`&XMZu%; zFU>McgqTWGJ)2KP9)7D8jqO99O`O{2nR7VM%s{iZ0rroSaR7xt;E@D>zds8f*WTAs zSE?tWed&9mYwvKIDSgp0As zK_)isLY9Hn2oGx^_&;0y3o0cwfb--u{lj`hslj=y_%oZ*%C2^o*e%{Nw_pDx8 z25!7YgR2_QQ6X@i{jRj!RFCAQ-H}5~SC4V@IgiPhIAu8d7F7@SG4{fZsBxDp<=L*45PQ+;%&{nv|XWu#-4VuGX6R!Dy@49;{;=+pO4xy+K;L))7i+YDDY=? zqy^T;@QJp$yQ{7e4;tf?4_+3pOZ&&SHLD)c9~e3+)?(6~@VzoJ7XOVx<^G^hbw*}X z2qEVEB$cJZ=Ig1@ZXLv22hM*8(L4bB$Eq>Tf6&yBbVFM37c^Ic%U-0nO|wsRzidJJ z;f}Hh#~sxPQJ4xKKZLaSSn=L1er4I+OxF9mn6zQ>sz3-%6LaEl1J4d6xfpmLVk20S z@oH=cuJH*Im7PKM|NJ}iem?>gVt86dFlZ;vj%G%1qiM?HbrV^a@?;SM?sbtB{Am;U zZ!i3*>jh$Ls=W#V_RhQ#n+wt*UVj)u-T#C@>ei38fC=HnU^5WC@O6iOh*vWL6`~z@ z#Y(c0#?-w&=7DPpM}r+v)Qc%X=f~-<;Rc0^Dr|DV0)@CAi3&-UClG-{Nrvre>+PFz zj1#~mO_`}r(6BYdI~FH}Yi*!@u6OA;1Mq}br;Nh%RI~TeLVy)NOsJAZy8JpR>Tx^CH-GX-mWz4JR3ilzsYZ3i`{nWdTFB2d<1sf%G^Rq!czXoF!_+5& zC0y|g-1W;ufDS4qFakT8ADm~10;B7|BQO^Eb!v^{toj|MyFRMLvaodSjuwom>VtxO z91w5=0_=+Oh*(ShOu!>nKuJL8p{Jvxl_|St9ZziHwAGH5d{PC|g^<^_fNhJD;{R`w zK5_z+)DN&cusN3wmztKwBT*sv-W@;?y%90sI@Fu~D+#*_PcM8bwF|L$So_li`Sx+a zs~53KI4y?U!9m>5>z(ZM<2inh`4SiJZF8x!geOl&B)R?SX0pfUSfc9(*|NR*Zmb<; z7Ur=dnSry2JnyNx4%nPRhjKkCmMS{*J8dp& ziDS~8<3}GJXNA-GT>&sFOvWwaSW&5KnkUswiZ4~i9mCeY)|VaY9(MJ|-lK3{ zb5-1x9Xaj{AP)=24VfzvA27!yG%85oPHC-xMkU0&8zQotkPWYwtBIex!SbB`OGJ1_ zX-Dt73C#7^LPc%@1cN$9xDK@C0(cuYpsoZWLr{{~nDvm(&o4ElJem)utNnYL{Rj`4 zihD#>H})a$x;QR1e-hkTtJiVH6)5K_U|ehCORb2$yYKt?61g5;wf3p!NVOpPn~OQm zpNsjZ?J~o~SX=ZdA{LoUR#jmAf)3!}d1u&=sf~{LD=pu*8;)g+$y;dahPFDBiGZGJ;sR+F7RtpvW<76zddN%8YQW!88n`J9Sza? zeMhCmyOwM9payb542u4kHK~v3j{j_$Q@ZG06U5!cZNN?eZan*Y3+_$Pt{Z&Ppys^W z+QL+a+~0=t*5j$_C{3Y1TW7xwqL2r00gWk%@0A?hKHwZ9lks&*Zg$;g+=mQ$kABEE zuTL{>x&`HQ&*R!g7dSyH1CNOW71DvXlKr_<4E*~ngC(>KNN|}SJ(GtpU2u%b#qyHg zMO_6fFFfS0Aqv?6`%|VSvOxkW%`p?mcs&fY6-WfP!0dIg=X&lEAAWI z(b1K&2hT?+Ct@s*3A!)AFdWvG%HxHKl8DvnwUf8)!~rv4@CRr&CyL!;`)BoX)Ie7O zV4efHJ!2(sYk%r8Y^-a$x3djP6|I z0=!C4iZOKzL?OL*UOwFscoj8jF0!;G>gISJl#KhR8R@-LO3lyK+{O)jRwy%!>qnt z6V5%IGTENiPrd!spB5Dy9oc0vRlxU#CYsONJb=u*l2c{^>!UfDt`G{OZ*3?9psSae zk#iI3%ko{fnR@$_yly((iE0h{juoD88uSdh181!Z847$ayxY9f@6}c@&q2BOEM3&o zpOgpaitS3~ZrnaA7svGk*k{!lZvwXjNj=QxSGik1dUz;q!}@R8(3v_OA8_T!@Bnh) znfZXg=kzA*au-D5PV;wllYd5en~l3?nC!h& z^({p%7Gc>C{jiBFyz6wDR76(4~?&?zLP48XFoW`zj;1 zMKbg{qP4!{p^)=;fiG#5py$T4r8UL(a}~)YxJ!n_EDvB&8-1_XL<{ zYhwtxN7dC}?bh5nTHWPk%g$Sj2rc+N=W=k} zqd1m570j|jcl2l&#HOW1M}2WF?#Abt))s7U^!JysFEY3`fHloJjtef6Ej%%>?=cB& z)|q;hvepT%v3GV^+mlWB@UeA@2JT-=V4D!#KWVQgXx@5#BsoA?mEp(NwD*p|y9dG) z6SHS$B%{95SUAgA(yk4;t*ak3d!3h@eKA916{NAF&^+~JgZ3|SO`jVzCuP1Nr2}V$ z5s4p}-M*(>+YxbTIUo8|jOLu5 zQanX2f=bRDp*)|~jvCOb+Ih9uOK7mc`{dB)GPBM6<)AX3bVQZNFx$13 z-Jf%=J`(l~L0c%uC<^0=j^7Bl+wPY7F6ca>ARK+Zc9X*ZU+_#WTd(k2V;R(!;}PCN z*&h`@j&(NWQRBa13w@h?x(BQ($6GWufF9}E0+}(#I|g}q`t0q6<0{{A51;sxFjaYU zt0I(&^VEV~qs;Wd%I?=htL#u^Yuu zg9CSkPmK_RuVr@sk6{Xsdd5wf77durr`hIZ)8+k5`=vcMLW{3xf-n^em6WXj zu}S~LtoYl~1WvKgu}HoKfbZ_fz&v zJ5;jGz#i8Zvm^1J(H`_>KY;hezvjdIg|ut09JZ8pC5f!^OlCh0K8fjjSs@Srm)u>c z@1|>DV)L^La-(qSPOQzuI*n0UESsrcnm&NmosH3Ho@B6(tB$m3bsP4aGUqTNzt5Z8 z(W)D(-ITC0^WR40s5Iq3;$^8wWp75>v z34}Sjo~KVa{f-}yi8ZR=k*HEi`0O*w&BnYpwX0Ygx##23HuTKjO@Ew`DH>i>Tz98nj)?XP4~&^cr zx0gj&d-p6t@X7+{>E&x{r>ePYS*9>~r?P_65lO%1gv@$JXts^gu Date: Tue, 11 Feb 2025 19:52:45 -0800 Subject: [PATCH 03/10] Remove redundant TODO comment --- handler.go | 1 - 1 file changed, 1 deletion(-) diff --git a/handler.go b/handler.go index 1444394..f7ed79b 100644 --- a/handler.go +++ b/handler.go @@ -137,7 +137,6 @@ func (h *Handler) Handle(_ context.Context, rec slog.Record) error { if h.opts.AddSource && rec.PC > 0 { h.enc.writeSource(buf, rec.PC, cwd) } - // TODO: Add indentation here. h.enc.writeMessage(buf, rec.Level, h.indentMsg(rec.Message)) buf.copy(&h.context) rec.Attrs(func(a slog.Attr) bool { From 7f06300c1c9fa7d4166a96bc1cfee6e5eccbdd1a Mon Sep 17 00:00:00 2001 From: "Marc M. Adkins" Date: Fri, 14 Feb 2025 07:29:54 -0800 Subject: [PATCH 04/10] Added DepthValuer, updated comments and README --- README.md | 157 +++++++++++++++++++++++++-------- examples/indent/main.go | 24 +++--- examples/indentValuer/main.go | 32 +++++++ handler.go | 158 ++++++++++++++++++++++------------ 4 files changed, 265 insertions(+), 106 deletions(-) create mode 100644 examples/indentValuer/main.go diff --git a/README.md b/README.md index cf47cca..ec76b02 100644 --- a/README.md +++ b/README.md @@ -75,32 +75,44 @@ BenchmarkLoggers/std-json-4 393322 2909 ns/op ``` ## Indentation -`console.Handler` also implements the custom interface: -```go -type Indenter interface { - // SetIndentation configures the prefix and indent strings. - // The prefix, if any, is added first, - // then the indent string is added as many times as the current depth. - SetIndentation(prefix, indent string) - - // Increment the indentation depth. - Increment() - - // Decrement the indentation depth. - // If the current depth is already zero there is no change. - Decrement() -} -``` Indentation of functions can occasionally be useful for delineating calls by indenting callees more than callers. +This can sometimes help interpret logs during development. -This isn't something that `log.slog` provides. -It is necessary to provide the handler pointer as a global variable or function -in order to use the `Indenter` interface. +The specific case of runaway recursion shows up clearly as the messages +march repeatedly across the screen. -Because the current `depth` is stored within the `console.Handler` this functionality is not thread-safe. -In order to use it in a multi-thread environment there must be a handler (and logger) for each thread, -and these items must be passed down through all intervening function calls (in lieu of thread variables). +Indentation is configured using `console.HandlerOptins.Indent` which uses the following type: +```go +// Indentation configures indentation for message and attribute data. +// If both Prefix and Tab strings are empty ("") indentation will not occur. +// When indenting, the message is prepended by the Prefix string (if not empty) +// followed by the depth level iterations of the Tab string. +// The depth level is provided by an attribute named by the Key string. +// This should be either an integer or a pointer to a DepthLevel object. +type Indentation struct { +// Prefix string used before indentation (optional). +Prefix string + +// Tab represents the additional indentation per depth level. +// It is probably better to not use an actual tab character here, +// but instead use some number of spaces. +Tab string + +// Key is the attribute key that will hold the depth number. +// When not provided the key is set to "depth". +Key string +}} +``` +A convenience function can be used instead of +filling out the `console.HandlerOptins.Indent` object manually for simple cases: +```go +// DefaultIndentation returns an Indentation struct with the specified tag string, +// no Prefix string, and Key set to the default indentation key. +// Other configurations (e.g. featuring a Prefix or non-default Key) +// must be set manually. +func DefaultIndentation(tab string) Indentation +``` ### Example @@ -114,32 +126,101 @@ import ( "github.com/phsym/console-slog" ) -var hdlr *console.Handler - func main() { - hdlr = console.NewHandler(os.Stderr, &console.HandlerOptions{Level: slog.LevelDebug}) - hdlr.SetIndentation("", " ") - slog.SetDefault(slog.New(hdlr)) - slog.Info("factorial", "result", factorial(7)) + slog.SetDefault(slog.New(console.NewHandler(os.Stderr, &console.HandlerOptions{ + Level: slog.LevelDebug, + Indent: console.DefaultIndentation(" "), + }))) + slog.Info("factorial", "result", factorial(7, 0)) } -func factorial(number uint) uint { - hdlr.Increment() - defer hdlr.Decrement() - - slog.Debug("factorial", "number", number) - var result uint +func factorial(number, depth int64) int64 { + slog.Debug("factorial", "number", number, "depth", depth) + var result int64 if number < 2 { result = 1 } else { - result = number * factorial(number-1) + result = number * factorial(number-1, depth+1) } - slog.Debug("factorial", "result", result) + slog.Debug("factorial", "result", result, "depth", depth) return result } ``` ![factorial-indent](./doc/img/factorial-indent.png) -The specific case of runaway recursion shows up clearly as the messages -march repeatedly across the screen. \ No newline at end of file +Where passing the depth number as an argument is contraindicated or just plain irritating +it is possible to use the following object for the depth value in logging statements: +```go +// DepthValuer represents an indentation depth object (an int64). +// These objects can be incremented on entry to a function and decremented in a defer statement. +// This object is not thread safe. Using it as a global variable (the mostly likely usage) +// in a multithreaded application will result in unpredictable values in different threads. +type DepthValuer struct { + depth int +} + +// LogValue implements the slog.LogValuer interface. +func (dv *DepthValuer) LogValue() slog.Value { + return slog.IntValue(int(dv.depth)) +} + +// Increment the depth value. +// Use this at the head of a function or important code block. +func (dv *DepthValuer) Increment() { + dv.depth += 1 +} + +// Decrement the depth value. +// Use this after an important code block or as a defer statement in a function. +func (dv *DepthValuer) Decrement() { + dv.depth -= 1 +} +``` + +The use case for `DepthValuer` is to invoke its `Increment()` function at the start of a function, +followed by a `defer` of its `Decrement()` object. +All logging calls in the function need to append the `Indentation.Key` and a pointer to the `DepthValuer`. + +_It is not possible_ to add this attribute via a `WithAttrs()` call as the value is +only evaluated once and cached by the `console.Handler` for performance reasons. +The `Indentation.Key` and `DepthValuer` pointer must be specified in each logging call. + +This mechanism should be usable in code blocks but `defer` doesn't work in this case. +The programmer is responsible for making certain that the `Decrement()` call is made in all situations. + +## Example: +```go +package main + +import ( + "log/slog" + "os" + + "github.com/phsym/console-slog" +) + +var depthValuer = &console.DepthValuer{} + +func main() { + slog.SetDefault(slog.New(console.NewHandler(os.Stderr, &console.HandlerOptions{ + Level: slog.LevelDebug, + Indent: console.DefaultIndentation(" "), + }))) + slog.Info("factorial", "result", factorial(7)) +} + +func factorial(number int64) int64 { + depthValuer.Increment() + defer depthValuer.Decrement() + slog.Debug("factorial", "number", number, "depth", depthValuer) + var result int64 + if number < 2 { + result = 1 + } else { + result = number * factorial(number-1) + } + slog.Debug("factorial", "result", result, "depth", depthValuer) + return result +} +``` \ No newline at end of file diff --git a/examples/indent/main.go b/examples/indent/main.go index 5317233..60c4f0f 100644 --- a/examples/indent/main.go +++ b/examples/indent/main.go @@ -7,26 +7,22 @@ import ( "github.com/phsym/console-slog" ) -var hdlr *console.Handler - func main() { - hdlr = console.NewHandler(os.Stderr, &console.HandlerOptions{Level: slog.LevelDebug}) - hdlr.SetIndentation("", " ") - slog.SetDefault(slog.New(hdlr)) - slog.Info("factorial", "result", factorial(7)) + slog.SetDefault(slog.New(console.NewHandler(os.Stderr, &console.HandlerOptions{ + Level: slog.LevelDebug, + Indent: console.DefaultIndentation(" "), + }))) + slog.Info("factorial", "result", factorial(7, 0)) } -func factorial(number uint) uint { - hdlr.Increment() - defer hdlr.Decrement() - - slog.Debug("factorial", "number", number) - var result uint +func factorial(number, depth int64) int64 { + slog.Debug("factorial", "number", number, "depth", depth) + var result int64 if number < 2 { result = 1 } else { - result = number * factorial(number-1) + result = number * factorial(number-1, depth+1) } - slog.Debug("factorial", "result", result) + slog.Debug("factorial", "result", result, "depth", depth) return result } diff --git a/examples/indentValuer/main.go b/examples/indentValuer/main.go new file mode 100644 index 0000000..a965894 --- /dev/null +++ b/examples/indentValuer/main.go @@ -0,0 +1,32 @@ +package main + +import ( + "log/slog" + "os" + + "github.com/phsym/console-slog" +) + +var depthValuer = &console.DepthValuer{} + +func main() { + slog.SetDefault(slog.New(console.NewHandler(os.Stderr, &console.HandlerOptions{ + Level: slog.LevelDebug, + Indent: console.DefaultIndentation(" "), + }))) + slog.Info("factorial", "result", factorial(7)) +} + +func factorial(number int64) int64 { + depthValuer.Increment() + defer depthValuer.Decrement() + slog.Debug("factorial", "number", number, "depth", depthValuer) + var result int64 + if number < 2 { + result = 1 + } else { + result = number * factorial(number-1) + } + slog.Debug("factorial", "result", result, "depth", depthValuer) + return result +} diff --git a/handler.go b/handler.go index f7ed79b..bc44c2e 100644 --- a/handler.go +++ b/handler.go @@ -38,62 +38,73 @@ type HandlerOptions struct { // Theme defines the colorized output using ANSI escape sequences Theme Theme -} - -type Indenter interface { - // SetIndentation configures the prefix and indent strings. - // The prefix, if any, is added first, - // then the indent string is added as many times as the current depth. - SetIndentation(prefix, indent string) - // Increment the indentation depth. - Increment() - - // Decrement the indentation depth. - // If the current depth is already zero there is no change. - Decrement() + // Indent defines a way for the message and attributes to be indented. + Indent Indentation } -// indentation defines support data for enhanced message and arg indentation by depth. -type indentation struct { - // Prefix for indentation string. - prefix string - - // Indent string for each depth level. - indent string - - // Depth is the current indentation depth - depth uint +const defaultIndentKey = "depth" + +// Indentation configures indentation for message and attribute data. +// If both Prefix and Tab strings are empty ("") indentation will not occur. +// When indenting, the message is prepended by the Prefix string (if not empty) +// followed by the depth level iterations of the Tab string. +// The depth level is provided by an attribute named by the Key string. +// This should be either an integer or a pointer to a DepthLevel object. +type Indentation struct { + // Prefix string used before indentation (optional). + Prefix string + + // Tab represents the additional indentation per depth level. + // It is probably better to not use an actual tab character here, + // but instead use some number of spaces. + Tab string + + // Key is the attribute key that will hold the depth number. + // When not provided the key is set to "depth". + Key string } -func (hd *indentation) indentMsg(msg string) string { - if hd.prefix == "" && (hd.indent == "" || hd.depth < 1) { - // No indentation. - return msg +func (indent *Indentation) indentString(depth int64) string { + if indent.isZero() || depth <= 0 { + return "" } - // Build indentation string. builder := strings.Builder{} - if hd.prefix != "" { - builder.WriteString(hd.prefix) + if indent.Prefix != "" { + builder.WriteString(indent.Prefix) } - if hd.indent != "" && hd.depth > 0 { - var i uint - for i = 0; i < hd.depth; i++ { - builder.WriteString(hd.indent) + if indent.Tab != "" { + // TODO: Is there a more efficient way to do this? + var i int64 + for i = 0; i < depth; i++ { + builder.WriteString(indent.Tab) } } - builder.WriteString(msg) return builder.String() } +// DefaultIndentation returns an Indentation struct with the specified tag string, +// no Prefix string, and Key set to the default indentation key. +// Other configurations (e.g. featuring a Prefix or non-default Key) +// must be set manually. +func DefaultIndentation(tab string) Indentation { + return Indentation{ + Tab: " ", + Key: defaultIndentKey, + } +} + +func (indent *Indentation) isZero() bool { + return indent.Prefix == "" && indent.Tab == "" +} + type Handler struct { opts HandlerOptions out io.Writer group string context buffer enc *encoder - indentation } var _ slog.Handler = (*Handler)(nil) @@ -114,6 +125,9 @@ func NewHandler(out io.Writer, opts *HandlerOptions) *Handler { if opts.Theme == nil { opts.Theme = NewDefaultTheme() } + if opts.Indent.Key == "" { + opts.Indent.Key = defaultIndentKey + } return &Handler{ opts: *opts, // Copy struct out: out, @@ -123,7 +137,7 @@ func NewHandler(out io.Writer, opts *HandlerOptions) *Handler { } } -// Enabled implements slog.Handler. +// / Enabled implements slog.Handler. func (h *Handler) Enabled(_ context.Context, l slog.Level) bool { return l >= h.opts.Level.Level() } @@ -137,12 +151,40 @@ func (h *Handler) Handle(_ context.Context, rec slog.Record) error { if h.opts.AddSource && rec.PC > 0 { h.enc.writeSource(buf, rec.PC, cwd) } - h.enc.writeMessage(buf, rec.Level, h.indentMsg(rec.Message)) - buf.copy(&h.context) - rec.Attrs(func(a slog.Attr) bool { - h.enc.writeAttr(buf, a, h.group) - return true - }) + if h.opts.Indent.isZero() { + h.enc.writeMessage(buf, rec.Level, rec.Message) + buf.copy(&h.context) + rec.Attrs(func(a slog.Attr) bool { + h.enc.writeAttr(buf, a, h.group) + return true + }) + } else { + // NewHandler() should always set h.opts.IndentKey to a non-empty value. + key := h.opts.Indent.Key + // Indent the message and attributes. + // Can't just ask for the depth key, must iterate through attributes. + var attributes []slog.Attr + var depth int64 + rec.Attrs(func(a slog.Attr) bool { + if a.Key == key { + value := a.Value + if value.Kind() == slog.KindLogValuer { + value = a.Value.LogValuer().LogValue() + } + if value.Kind() == slog.KindInt64 { + depth = value.Int64() + } + } else { + attributes = append(attributes, a) + } + return true + }) + h.enc.writeMessage(buf, rec.Level, h.opts.Indent.indentString(depth)+rec.Message) + buf.copy(&h.context) + for _, a := range attributes { + h.enc.writeAttr(buf, a, h.group) + } + } h.enc.NewLine(buf) if _, err := buf.WriteTo(h.out); err != nil { buf.Reset() @@ -184,20 +226,28 @@ func (h *Handler) WithGroup(name string) slog.Handler { } } -var _ Indenter = (*Handler)(nil) +// DepthValuer represents an indentation depth object (an int64). +// These objects can be incremented on entry to a function and decremented in a defer statement. +// Use a pointer to a DepthValuer object in logging statements, do not pass the object itself. +// This object is not thread safe. Using it as a global variable (the mostly likely usage) +// in a multithreaded application will result in unpredictable values in different threads. +type DepthValuer struct { + depth int +} -func (h *Handler) SetIndentation(prefix, indent string) { - h.prefix = prefix - h.indent = indent - h.depth = 0 +// LogValue implements the slog.LogValuer interface. +func (dv *DepthValuer) LogValue() slog.Value { + return slog.IntValue(int(dv.depth)) } -func (h *Handler) Increment() { - h.depth++ +// Increment the depth value. +// Use this at the head of a function or important code block. +func (dv *DepthValuer) Increment() { + dv.depth += 1 } -func (h *Handler) Decrement() { - if h.depth > 0 { - h.depth-- - } +// Decrement the depth value. +// Use this after an important code block or as a defer statement in a function. +func (dv *DepthValuer) Decrement() { + dv.depth -= 1 } From 0adf734acbd91fb8fdc9f7104b0864d191f009d5 Mon Sep 17 00:00:00 2001 From: "Marc M. Adkins" Date: Fri, 14 Feb 2025 19:32:28 -0800 Subject: [PATCH 05/10] Add indent bench test and minor handler fixes for indent code --- bench_test.go | 31 ++++++++++++++++++++++++++++++- handler.go | 10 ++-------- 2 files changed, 32 insertions(+), 9 deletions(-) diff --git a/bench_test.go b/bench_test.go index 88736ac..62d1a13 100644 --- a/bench_test.go +++ b/bench_test.go @@ -24,6 +24,8 @@ var handlers = []struct { {"console", NewHandler(io.Discard, &HandlerOptions{Level: slog.LevelDebug, AddSource: false})}, {"std-text", slog.NewTextHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug, AddSource: false})}, {"std-json", slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug, AddSource: false})}, + {"console-indent", NewHandler(io.Discard, &HandlerOptions{Level: slog.LevelDebug, Indent: DefaultIndentation(" ")})}, + //{"console-ind-valuer", NewHandler(io.Discard, &HandlerOptions{Level: slog.LevelDebug, Indent: DefaultIndentation(" ")})}, } var attrs = []slog.Attr{ @@ -61,12 +63,38 @@ func BenchmarkHandlers(b *testing.B) { } }) } + b.ReportAllocs() } -func BenchmarkLoggers(b *testing.B) { +func BenchmarkHandlersIndent(b *testing.B) { + ctx := context.Background() + rec := slog.NewRecord(time.Now(), slog.LevelInfo, "hello", 0) + rec.AddAttrs(attrs...) + rec.AddAttrs(slog.Attr{ + Key: "depth", + Value: slog.IntValue(5), + }) + + for _, tc := range handlers { + b.Run(tc.name, func(b *testing.B) { + l := tc.hdl.WithAttrs(attrs).WithGroup("test").WithAttrs(attrs) + // Warm-up + _ = l.Handle(ctx, rec) + b.ResetTimer() + for i := 0; i < b.N; i++ { + _ = l.Handle(ctx, rec) + } + }) + } + b.ReportAllocs() +} + +func BenchmarkLoggersIndent(b *testing.B) { for _, tc := range handlers { ctx := context.Background() b.Run(tc.name, func(b *testing.B) { + attrsIndent := attrs + attrsIndent = append(attrsIndent, slog.Int64("depth", 5)) l := slog.New(tc.hdl).With(attrsAny...).WithGroup("test").With(attrsAny...) // Warm-up l.LogAttrs(ctx, slog.LevelInfo, "hello", attrs...) @@ -76,4 +104,5 @@ func BenchmarkLoggers(b *testing.B) { } }) } + b.ReportAllocs() } diff --git a/handler.go b/handler.go index bc44c2e..b32a5bc 100644 --- a/handler.go +++ b/handler.go @@ -75,11 +75,7 @@ func (indent *Indentation) indentString(depth int64) string { builder.WriteString(indent.Prefix) } if indent.Tab != "" { - // TODO: Is there a more efficient way to do this? - var i int64 - for i = 0; i < depth; i++ { - builder.WriteString(indent.Tab) - } + builder.WriteString(strings.Repeat(indent.Tab, int(depth))) } return builder.String() } @@ -159,14 +155,12 @@ func (h *Handler) Handle(_ context.Context, rec slog.Record) error { return true }) } else { - // NewHandler() should always set h.opts.IndentKey to a non-empty value. - key := h.opts.Indent.Key // Indent the message and attributes. // Can't just ask for the depth key, must iterate through attributes. var attributes []slog.Attr var depth int64 rec.Attrs(func(a slog.Attr) bool { - if a.Key == key { + if a.Key == h.opts.Indent.Key { value := a.Value if value.Kind() == slog.KindLogValuer { value = a.Value.LogValuer().LogValue() From 9d2257bdabe690f35c40a7edcf9f7dd067d39426 Mon Sep 17 00:00:00 2001 From: "Marc M. Adkins" Date: Fri, 14 Feb 2025 20:07:18 -0800 Subject: [PATCH 06/10] Reduce memory allocations, possibly increasing processing time --- handler.go | 24 +++++++++--------------- 1 file changed, 9 insertions(+), 15 deletions(-) diff --git a/handler.go b/handler.go index b32a5bc..cc0cccb 100644 --- a/handler.go +++ b/handler.go @@ -69,15 +69,7 @@ func (indent *Indentation) indentString(depth int64) string { if indent.isZero() || depth <= 0 { return "" } - // Build indentation string. - builder := strings.Builder{} - if indent.Prefix != "" { - builder.WriteString(indent.Prefix) - } - if indent.Tab != "" { - builder.WriteString(strings.Repeat(indent.Tab, int(depth))) - } - return builder.String() + return indent.Prefix + strings.Repeat(indent.Tab, int(depth)) } // DefaultIndentation returns an Indentation struct with the specified tag string, @@ -155,9 +147,9 @@ func (h *Handler) Handle(_ context.Context, rec slog.Record) error { return true }) } else { + // Indent the message and attributes. - // Can't just ask for the depth key, must iterate through attributes. - var attributes []slog.Attr + // Can't just ask for the depth key, must iterate through attributes to find it. var depth int64 rec.Attrs(func(a slog.Attr) bool { if a.Key == h.opts.Indent.Key { @@ -167,17 +159,19 @@ func (h *Handler) Handle(_ context.Context, rec slog.Record) error { } if value.Kind() == slog.KindInt64 { depth = value.Int64() + // If multiple depth key entries only the first one is used. + return false } - } else { - attributes = append(attributes, a) } return true }) h.enc.writeMessage(buf, rec.Level, h.opts.Indent.indentString(depth)+rec.Message) buf.copy(&h.context) - for _, a := range attributes { + // Second iteration over attributes to push them onto the encoder. + rec.Attrs(func(a slog.Attr) bool { h.enc.writeAttr(buf, a, h.group) - } + return true + }) } h.enc.NewLine(buf) if _, err := buf.WriteTo(h.out); err != nil { From 9ef6635fc50f2496bfbfc0ccce2ef2ecbfa9e5d5 Mon Sep 17 00:00:00 2001 From: "Marc M. Adkins" Date: Fri, 14 Feb 2025 20:09:51 -0800 Subject: [PATCH 07/10] Move console indent handler to be next to console handler in benchmark results --- bench_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bench_test.go b/bench_test.go index 62d1a13..9bc28ed 100644 --- a/bench_test.go +++ b/bench_test.go @@ -22,9 +22,9 @@ var handlers = []struct { }{ {"dummy", &DummyHandler{}}, {"console", NewHandler(io.Discard, &HandlerOptions{Level: slog.LevelDebug, AddSource: false})}, + {"console-indent", NewHandler(io.Discard, &HandlerOptions{Level: slog.LevelDebug, Indent: DefaultIndentation(" ")})}, {"std-text", slog.NewTextHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug, AddSource: false})}, {"std-json", slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug, AddSource: false})}, - {"console-indent", NewHandler(io.Discard, &HandlerOptions{Level: slog.LevelDebug, Indent: DefaultIndentation(" ")})}, //{"console-ind-valuer", NewHandler(io.Discard, &HandlerOptions{Level: slog.LevelDebug, Indent: DefaultIndentation(" ")})}, } From 4d0f51e2f0034a5e90b1deafd0d12287c2a790a4 Mon Sep 17 00:00:00 2001 From: "Marc M. Adkins" Date: Sat, 15 Feb 2025 03:54:15 -0800 Subject: [PATCH 08/10] Document benchmarks of indent code --- README.md | 20 +++++++++++++++++++- bench_test.go | 3 +++ 2 files changed, 22 insertions(+), 1 deletion(-) diff --git a/README.md b/README.md index ec76b02..302ba07 100644 --- a/README.md +++ b/README.md @@ -189,7 +189,7 @@ The `Indentation.Key` and `DepthValuer` pointer must be specified in each loggin This mechanism should be usable in code blocks but `defer` doesn't work in this case. The programmer is responsible for making certain that the `Decrement()` call is made in all situations. -## Example: +### Example: ```go package main @@ -223,4 +223,22 @@ func factorial(number int64) int64 { slog.Debug("factorial", "result", result, "depth", depthValuer) return result } +``` +### Performances +See [benchmark file](./bench_test.go) for details. + +Benchmark results comparing console numbers with and without indentation testing: +``` +goos: linux +goarch: amd64 +pkg: github.com/phsym/console-slog +cpu: Intel(R) Core(TM) i7-7820HQ CPU @ 2.90GHz +benchmark iter time/iter bytes alloc allocs +--------- ---- --------- ----------- ------ +BenchmarkHandlers/console-8 780844 1496.00 ns/op 0 B/op 0 allocs/op +BenchmarkHandlers/console-indent-8 745261 1578.00 ns/op 0 B/op 0 allocs/op +BenchmarkHandlersIndent/console-8 700791 1614.00 ns/op 0 B/op 0 allocs/op +BenchmarkHandlersIndent/console-indent-8 694560 1746.00 ns/op 0 B/op 0 allocs/op +BenchmarkLoggersIndent/console-8 574340 1983.00 ns/op 128 B/op 1 allocs/op +BenchmarkLoggersIndent/console-indent-8 520488 2277.00 ns/op 128 B/op 1 allocs/op ``` \ No newline at end of file diff --git a/bench_test.go b/bench_test.go index 9bc28ed..13bddc8 100644 --- a/bench_test.go +++ b/bench_test.go @@ -1,5 +1,8 @@ package console +// Run with go test -bench=. -test.benchmem | prettybench +// Get pretty bench with go install github.com/cespare/prettybench@latest + import ( "context" "errors" From 3aa1edc4b49d429c4cd0efb9062323f90826d13f Mon Sep 17 00:00:00 2001 From: "Marc M. Adkins" Date: Sat, 15 Feb 2025 09:51:58 -0800 Subject: [PATCH 09/10] Add factorial benchmark to test DepthValuer --- README.md | 34 ++++++++++++++++++++++++++-------- bench_test.go | 28 +++++++++++++++++++++++++--- 2 files changed, 51 insertions(+), 11 deletions(-) diff --git a/README.md b/README.md index 302ba07..613cb96 100644 --- a/README.md +++ b/README.md @@ -233,12 +233,30 @@ goos: linux goarch: amd64 pkg: github.com/phsym/console-slog cpu: Intel(R) Core(TM) i7-7820HQ CPU @ 2.90GHz -benchmark iter time/iter bytes alloc allocs ---------- ---- --------- ----------- ------ -BenchmarkHandlers/console-8 780844 1496.00 ns/op 0 B/op 0 allocs/op -BenchmarkHandlers/console-indent-8 745261 1578.00 ns/op 0 B/op 0 allocs/op -BenchmarkHandlersIndent/console-8 700791 1614.00 ns/op 0 B/op 0 allocs/op -BenchmarkHandlersIndent/console-indent-8 694560 1746.00 ns/op 0 B/op 0 allocs/op -BenchmarkLoggersIndent/console-8 574340 1983.00 ns/op 128 B/op 1 allocs/op -BenchmarkLoggersIndent/console-indent-8 520488 2277.00 ns/op 128 B/op 1 allocs/op +enchmark iter time/iter bytes alloc allocs +--------- ---- --------- ----------- ------ +BenchmarkHandlers/dummy-8 167386000 7.28 ns/op 0 B/op 0 allocs/op +BenchmarkHandlers/console-8 773392 1490.00 ns/op 0 B/op 0 allocs/op +BenchmarkHandlers/console-indent-8 724384 1601.00 ns/op 0 B/op 0 allocs/op +BenchmarkHandlers/std-text-8 682894 1676.00 ns/op 2 B/op 1 allocs/op +BenchmarkHandlers/std-json-8 793027 1501.00 ns/op 120 B/op 3 allocs/op +BenchmarkHandlersIndent/dummy-8 166353291 7.38 ns/op 0 B/op 0 allocs/op +BenchmarkHandlersIndent/console-8 644863 1657.00 ns/op 0 B/op 0 allocs/op +BenchmarkHandlersIndent/console-indent-8 699098 1754.00 ns/op 0 B/op 0 allocs/op +BenchmarkHandlersIndent/std-text-8 608865 1781.00 ns/op 2 B/op 1 allocs/op +BenchmarkHandlersIndent/std-json-8 696843 1574.00 ns/op 120 B/op 3 allocs/op +BenchmarkLoggersIndent/dummy-8 2955999 406.40 ns/op 128 B/op 1 allocs/op +BenchmarkLoggersIndent/console-8 543122 1953.00 ns/op 128 B/op 1 allocs/op +BenchmarkLoggersIndent/console-indent-8 540606 2033.00 ns/op 128 B/op 1 allocs/op +BenchmarkLoggersIndent/std-text-8 484188 2158.00 ns/op 130 B/op 2 allocs/op +BenchmarkLoggersIndent/std-json-8 562014 1996.00 ns/op 248 B/op 4 allocs/op +BenchmarkHandlersFactorial/dummy-8 8170125 145.30 ns/op 16 B/op 2 allocs/op +BenchmarkHandlersFactorial/console-8 7995117 144.20 ns/op 16 B/op 2 allocs/op +BenchmarkHandlersFactorial/console-indent-8 8149261 145.80 ns/op 16 B/op 2 allocs/op +BenchmarkHandlersFactorial/std-text-8 7979374 144.70 ns/op 16 B/op 2 allocs/op +BenchmarkHandlersFactorial/std-json-8 8365809 144.20 ns/op 16 B/op 2 allocs/op +BenchmarkBuffer/std-8 160528912 7.57 ns/op 0 B/op 0 allocs/op +BenchmarkBuffer/buffer-8 297744796 4.11 ns/op 0 B/op 0 allocs/op +BenchmarkDuration/std-8 30995145 38.00 ns/op 0 B/op 0 allocs/op +BenchmarkDuration/append-8 36095490 32.81 ns/op 0 B/op 0 allocs/op ``` \ No newline at end of file diff --git a/bench_test.go b/bench_test.go index 13bddc8..e9422d8 100644 --- a/bench_test.go +++ b/bench_test.go @@ -66,7 +66,6 @@ func BenchmarkHandlers(b *testing.B) { } }) } - b.ReportAllocs() } func BenchmarkHandlersIndent(b *testing.B) { @@ -89,7 +88,6 @@ func BenchmarkHandlersIndent(b *testing.B) { } }) } - b.ReportAllocs() } func BenchmarkLoggersIndent(b *testing.B) { @@ -107,5 +105,29 @@ func BenchmarkLoggersIndent(b *testing.B) { } }) } - b.ReportAllocs() +} + +func BenchmarkHandlersFactorial(b *testing.B) { + for _, tc := range handlers { + b.Run(tc.name, func(b *testing.B) { + b.ResetTimer() + for i := 0; i < b.N; i++ { + factorial(slog.New(tc.hdl), 7) + } + }) + } +} + +var depthValuer = &DepthValuer{} + +func factorial(logger *slog.Logger, number int) int { + depthValuer.Increment() + depthValuer.Decrement() + slog.Debug("factorial", "number", number, "depth", depthValuer) + if number <= 1 { + return 1 + } + result := number * factorial(logger, number-1) + slog.Debug("factorial", "result", result, "depth", depthValuer) + return result } From add0bbd5668c6368fd427294e6769ca5336db901 Mon Sep 17 00:00:00 2001 From: "Marc M. Adkins" Date: Sat, 15 Feb 2025 09:58:34 -0800 Subject: [PATCH 10/10] Remove commented out line for additional benchmark handler --- bench_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/bench_test.go b/bench_test.go index e9422d8..2a0ddd7 100644 --- a/bench_test.go +++ b/bench_test.go @@ -28,7 +28,6 @@ var handlers = []struct { {"console-indent", NewHandler(io.Discard, &HandlerOptions{Level: slog.LevelDebug, Indent: DefaultIndentation(" ")})}, {"std-text", slog.NewTextHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug, AddSource: false})}, {"std-json", slog.NewJSONHandler(io.Discard, &slog.HandlerOptions{Level: slog.LevelDebug, AddSource: false})}, - //{"console-ind-valuer", NewHandler(io.Discard, &HandlerOptions{Level: slog.LevelDebug, Indent: DefaultIndentation(" ")})}, } var attrs = []slog.Attr{ @@ -107,6 +106,7 @@ func BenchmarkLoggersIndent(b *testing.B) { } } +// BenchmarkHandlersFactorial tests the performance of the DepthValuer. func BenchmarkHandlersFactorial(b *testing.B) { for _, tc := range handlers { b.Run(tc.name, func(b *testing.B) {