From 34977614164fb80f3859fd86eb036bd49403c79a Mon Sep 17 00:00:00 2001 From: sam-at-luther Date: Wed, 7 Feb 2024 17:30:57 -0800 Subject: [PATCH] Enable profiling on anon functions --- lisp/env.go | 16 +++++++++---- lisp/lisp.go | 21 +++++++++++++++++ lisp/lisplib/libhelp/libhelp.go | 23 +------------------ lisp/lisplib/libhelp/libhelp_test.go | 10 +++----- lisp/x/profiler/funlabeler.go | 3 +-- .../profiler/opentelemetry_annotator_test.go | 7 +++--- lisp/x/profiler/skipfilter.go | 3 +-- lisp/x/profiler/test.lisp | 9 ++++++-- 8 files changed, 50 insertions(+), 42 deletions(-) diff --git a/lisp/env.go b/lisp/env.go index c8aba86..9d6af3e 100644 --- a/lisp/env.go +++ b/lisp/env.go @@ -866,10 +866,7 @@ func (env *LEnv) EvalSExpr(s *LVal) *LVal { fun := call.Cells[0] // call is not an empty expression -- fun is known LFun args := call args.Cells = args.Cells[1:] - if env.Runtime.Profiler != nil { - stop := env.Runtime.Profiler.Start(fun) - defer stop() - } + switch fun.FunType { case LFunNone: return env.FunCall(fun, args) @@ -979,6 +976,15 @@ func (env *LEnv) FunCall(fun, args *LVal) *LVal { return env.funCall(fun, args) } +func (env *LEnv) trace(fun *LVal) func() { + if env.Runtime.Profiler != nil { + // fun might be an anon function, so we need to convert it to get the + // right type of LVal for filtering and labeling + return env.Runtime.Profiler.Start(fun) + } + return func() {} +} + // FunCall invokes regular function fun with the argument list args. func (env *LEnv) funCall(fun, args *LVal) *LVal { if fun.Type != LFun { @@ -988,6 +994,8 @@ func (env *LEnv) funCall(fun, args *LVal) *LVal { return env.Errorf("not a regular function: %v", fun.FunType) } + defer env.trace(fun)() + // Check for possible tail recursion before pushing to avoid hitting s when // checking. But push FID onto the stack before popping to simplify // book-keeping. diff --git a/lisp/lisp.go b/lisp/lisp.go index 510ace0..9c0a06c 100644 --- a/lisp/lisp.go +++ b/lisp/lisp.go @@ -970,6 +970,27 @@ func (v *LVal) String() string { return v.str(false) } +// Docstring returns the docstring of the function reference v. If v is not +// a function Docstring returns the empty string. +func (v *LVal) Docstring() string { + if v.Type != LFun { + return "" + } + if v.Builtin() != nil { + if len(v.Cells) > 1 { + return v.Cells[1].Str + } + return "" + } + // Functions of the form (lambda (x) "abc") are considered constant string + // functions without documentation so there must be a length check on the + // function body. + if len(v.Cells) > 2 && v.Cells[1].Type == LString { + return v.Cells[1].Str + } + return "" +} + func (v *LVal) str(onTheRecord bool) string { const QUOTE = `'` // All types which may evaluate to things other than themselves must check diff --git a/lisp/lisplib/libhelp/libhelp.go b/lisp/lisplib/libhelp/libhelp.go index 8d9a40c..51e3a89 100644 --- a/lisp/lisplib/libhelp/libhelp.go +++ b/lisp/lisplib/libhelp/libhelp.go @@ -122,27 +122,6 @@ func sortedSymbols(smap map[string]*lisp.LVal) []string { return symbols } -// FunDocstring returns the docstring of the function reference v. If v is not -// a function FunDocstring returns the empty string. -func FunDocstring(v *lisp.LVal) string { - if v.Type != lisp.LFun { - return "" - } - if v.Builtin() != nil { - if len(v.Cells) > 1 { - return v.Cells[1].Str - } - return "" - } - // Functions of the form (lambda (x) "abc") are considered constant string - // functions without documentation so there must be a length check on the - // function body. - if len(v.Cells) > 2 && v.Cells[1].Type == lisp.LString { - return v.Cells[1].Str - } - return "" -} - // RenderPkgExported writes to w formatted documentation for exported symbols // in the query package within env. The exact formatting of the rendered // documentation is subject to change across elps versions. @@ -211,7 +190,7 @@ func renderFun(w io.Writer, sym string, v *lisp.LVal) error { if err != nil { return fmt.Errorf("rendering signature: %w", err) } - doc := cleanDocstring(FunDocstring(v)) + doc := cleanDocstring(v.Docstring()) if doc != "" { _, err = fmt.Fprintln(w, doc) return err diff --git a/lisp/lisplib/libhelp/libhelp_test.go b/lisp/lisplib/libhelp/libhelp_test.go index 5d37263..cec8489 100644 --- a/lisp/lisplib/libhelp/libhelp_test.go +++ b/lisp/lisplib/libhelp/libhelp_test.go @@ -7,7 +7,6 @@ import ( "github.com/luthersystems/elps/lisp" "github.com/luthersystems/elps/lisp/lisplib" - "github.com/luthersystems/elps/lisp/lisplib/libhelp" "github.com/luthersystems/elps/parser" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -30,8 +29,7 @@ func TestDocstring(t *testing.T) { for _, name := range builtinSymbols { fun := env.Get(lisp.Symbol(name)) if assert.Equal(t, lisp.LFun, fun.Type) { - docstring := libhelp.FunDocstring(fun) - assert.NotEqual(t, "", docstring) + assert.NotEqual(t, "", fun.Docstring()) } } @@ -43,12 +41,10 @@ func TestDocstring(t *testing.T) { lisp1 := env.Get(lisp.Symbol("const-string1")) if assert.Equal(t, lisp.LFun, lisp1.Type) { - docstring := libhelp.FunDocstring(lisp1) - assert.Equal(t, "", docstring) + assert.Equal(t, "", lisp1.Docstring()) } lisp2 := env.Get(lisp.Symbol("const-string2")) if assert.Equal(t, lisp.LFun, lisp2.Type) { - docstring := libhelp.FunDocstring(lisp2) - assert.Equal(t, "abc", docstring) + assert.Equal(t, "abc", lisp2.Docstring()) } } diff --git a/lisp/x/profiler/funlabeler.go b/lisp/x/profiler/funlabeler.go index 3425d3f..6664abe 100644 --- a/lisp/x/profiler/funlabeler.go +++ b/lisp/x/profiler/funlabeler.go @@ -6,7 +6,6 @@ import ( "strings" "github.com/luthersystems/elps/lisp" - "github.com/luthersystems/elps/lisp/lisplib/libhelp" ) // FunLabeler provides an alternative name for a function label in the trace. @@ -74,7 +73,7 @@ func docLabel(docStr string) string { } func elpsDocFunLabeler(runtime *lisp.Runtime, fun *lisp.LVal) string { - docStr := libhelp.FunDocstring(fun) + docStr := fun.Docstring() if docStr == "" { return "" } diff --git a/lisp/x/profiler/opentelemetry_annotator_test.go b/lisp/x/profiler/opentelemetry_annotator_test.go index d580374..7baa522 100644 --- a/lisp/x/profiler/opentelemetry_annotator_test.go +++ b/lisp/x/profiler/opentelemetry_annotator_test.go @@ -69,7 +69,8 @@ func TestNewOpenTelemetryAnnotatorSkip(t *testing.T) { assert.NoError(t, ppa.Complete()) spans := exporter.GetSpans() - assert.Equal(t, len(spans), 4, "Expected selective spans") - assert.Equal(t, spans[0].Name, "Add_It", "Expected 1st custom label") - assert.Equal(t, spans[3].Name, "Add_It_Again", "Expected 2nd custom label") + assert.Equal(t, 7, len(spans), "Expected selective spans") + assert.Equal(t, "Add_It", spans[0].Name, "Expected custom label") + assert.Equal(t, "Add_It_Again", spans[3].Name, "Expected custom label") + assert.Equal(t, "lambda", spans[4].Name, "Expected custom label") } diff --git a/lisp/x/profiler/skipfilter.go b/lisp/x/profiler/skipfilter.go index 2ec7fb5..1a3e612 100644 --- a/lisp/x/profiler/skipfilter.go +++ b/lisp/x/profiler/skipfilter.go @@ -4,7 +4,6 @@ import ( "regexp" "github.com/luthersystems/elps/lisp" - "github.com/luthersystems/elps/lisp/lisplib/libhelp" ) type SkipFilter func(fun *lisp.LVal) bool @@ -41,7 +40,7 @@ const ELPSDocTrace = "@trace" var elpsDocTraceRegExp = regexp.MustCompile(ELPSDocTrace) func elpsDocSkipFilter(fun *lisp.LVal) bool { - docStr := libhelp.FunDocstring(fun) + docStr := fun.Docstring() if docStr == "" { return true } diff --git a/lisp/x/profiler/test.lisp b/lisp/x/profiler/test.lisp index ddad313..19580f1 100644 --- a/lisp/x/profiler/test.lisp +++ b/lisp/x/profiler/test.lisp @@ -11,10 +11,15 @@ (add-it x 3))) (print-it "Hello") -(print-it (add-it (add-it 3 (recurse-it 5)) 8)) +(print-it (add-it (add-it 3 (recurse-it 5)) 8)) ; span 1..3 (labels ([add-it-again (x) - "@trace { Add-It-Again }" + "@trace { Add-It-Again }" ; span 4 (+ x 1)]) (add-it-again 2)) + +(let ([l (lambda (x) "@trace{ lambda }" x)]) + (l 42)) ; span 5 + +(map () (lambda (x) "@trace" x) '(1 2)) ; span 6, 7