Skip to content

Commit 63a755d

Browse files
kyleconroykyleconroy
authored
feat: Instrument compiler via runtime/trace (#1258)
* feat: Instrument compiler via runtime/trace
1 parent 42a7cd6 commit 63a755d

File tree

6 files changed

+131
-25
lines changed

6 files changed

+131
-25
lines changed

‎internal/cmd/cmd.go

Lines changed: 29 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1,17 +1,21 @@
11
package cmd
22

33
import (
4+
"context"
45
"fmt"
56
"io"
67
"os"
78
"os/exec"
89
"path/filepath"
10+
"runtime/trace"
911

1012
"github.com/spf13/cobra"
1113
"github.com/spf13/pflag"
1214
yaml "gopkg.in/yaml.v3"
1315

1416
"github.com/kyleconroy/sqlc/internal/config"
17+
"github.com/kyleconroy/sqlc/internal/debug"
18+
"github.com/kyleconroy/sqlc/internal/tracer"
1519
)
1620

1721
// Do runs the command logic.
@@ -30,8 +34,14 @@ func Do(args []string, stdin io.Reader, stdout io.Writer, stderr io.Writer) int
3034
rootCmd.SetOut(stdout)
3135
rootCmd.SetErr(stderr)
3236

33-
err := rootCmd.Execute()
34-
if err == nil {
37+
ctx, cleanup, err := tracer.Start(context.Background())
38+
if err != nil {
39+
fmt.Printf("failed to start trace: %v\n", err)
40+
return 1
41+
}
42+
defer cleanup()
43+
44+
if err := rootCmd.ExecuteContext(ctx); err == nil {
3545
return 0
3646
}
3747
if exitError, ok := err.(*exec.ExitError); ok {
@@ -46,6 +56,9 @@ var versionCmd = &cobra.Command{
4656
Use: "version",
4757
Short: "Print the sqlc version number",
4858
Run: func(cmd *cobra.Command, args []string) {
59+
if debug.Traced {
60+
defer trace.StartRegion(cmd.Context(), "version").End()
61+
}
4962
if version == "" {
5063
// When no version is set, return the next bug fix version
5164
// after the most recent tag
@@ -60,6 +73,9 @@ var initCmd = &cobra.Command{
6073
Use: "init",
6174
Short: "Create an empty sqlc.yaml settings file",
6275
RunE: func(cmd *cobra.Command, args []string) error {
76+
if debug.Traced {
77+
defer trace.StartRegion(cmd.Context(), "init").End()
78+
}
6379
file := "sqlc.yaml"
6480
if f := cmd.Flag("file"); f != nil && f.Changed {
6581
file = f.Value.String()
@@ -114,12 +130,18 @@ var genCmd = &cobra.Command{
114130
Use: "generate",
115131
Short: "Generate Go code from SQL",
116132
Run: func(cmd *cobra.Command, args []string) {
133+
if debug.Traced {
134+
defer trace.StartRegion(cmd.Context(), "generate").End()
135+
}
117136
stderr := cmd.ErrOrStderr()
118137
dir, name := getConfigPath(stderr, cmd.Flag("file"))
119-
output, err := Generate(ParseEnv(cmd), dir, name, stderr)
138+
output, err := Generate(cmd.Context(), ParseEnv(cmd), dir, name, stderr)
120139
if err != nil {
121140
os.Exit(1)
122141
}
142+
if debug.Traced {
143+
defer trace.StartRegion(cmd.Context(), "writefiles").End()
144+
}
123145
for filename, source := range output {
124146
os.MkdirAll(filepath.Dir(filename), 0755)
125147
if err := os.WriteFile(filename, []byte(source), 0644); err != nil {
@@ -134,9 +156,12 @@ var checkCmd = &cobra.Command{
134156
Use: "compile",
135157
Short: "Statically check SQL for syntax and type errors",
136158
RunE: func(cmd *cobra.Command, args []string) error {
159+
if debug.Traced {
160+
defer trace.StartRegion(cmd.Context(), "compile").End()
161+
}
137162
stderr := cmd.ErrOrStderr()
138163
dir, name := getConfigPath(stderr, cmd.Flag("file"))
139-
if _, err := Generate(ParseEnv(cmd), dir, name, stderr); err != nil {
164+
if _, err := Generate(cmd.Context(), ParseEnv(cmd), dir, name, stderr); err != nil {
140165
os.Exit(1)
141166
}
142167
return nil

‎internal/cmd/generate.go

Lines changed: 35 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -2,11 +2,13 @@ package cmd
22

33
import (
44
"bytes"
5+
"context"
56
"errors"
67
"fmt"
78
"io"
89
"os"
910
"path/filepath"
11+
"runtime/trace"
1012
"strings"
1113

1214
"github.com/kyleconroy/sqlc/internal/codegen/golang"
@@ -44,7 +46,7 @@ type outPair struct {
4446
config.SQL
4547
}
4648

47-
func Generate(e Env, dir, filename string, stderr io.Writer) (map[string]string, error) {
49+
func Generate(ctx context.Context, e Env, dir, filename string, stderr io.Writer) (map[string]string, error) {
4850
configPath := ""
4951
if filename != "" {
5052
configPath = filepath.Join(dir, filename)
@@ -97,12 +99,6 @@ func Generate(e Env, dir, filename string, stderr io.Writer) (map[string]string,
9799
return nil, err
98100
}
99101

100-
debug, err := opts.DebugFromEnv()
101-
if err != nil {
102-
fmt.Fprintf(stderr, "error parsing SQLCDEBUG: %s\n", err)
103-
return nil, err
104-
}
105-
106102
output := map[string]string{}
107103
errored := false
108104

@@ -148,27 +144,43 @@ func Generate(e Env, dir, filename string, stderr io.Writer) (map[string]string,
148144
}
149145
sql.Queries = joined
150146

151-
var name string
147+
var name, lang string
152148
parseOpts := opts.Parser{
153-
Debug: debug,
149+
Debug: debug.Debug,
154150
}
155151
if sql.Gen.Go != nil {
156152
name = combo.Go.Package
153+
lang = "golang"
157154
} else if sql.Gen.Kotlin != nil {
158155
if sql.Engine == config.EnginePostgreSQL {
159156
parseOpts.UsePositionalParameters = true
160157
}
158+
lang = "kotlin"
161159
name = combo.Kotlin.Package
162160
} else if sql.Gen.Python != nil {
161+
lang = "python"
163162
name = combo.Python.Package
164163
}
165164

166-
result, failed := parse(e, name, dir, sql.SQL, combo, parseOpts, stderr)
165+
var packageRegion *trace.Region
166+
if debug.Traced {
167+
packageRegion = trace.StartRegion(ctx, "package")
168+
trace.Logf(ctx, "", "name=%s dir=%s language=%s", name, dir, lang)
169+
}
170+
171+
result, failed := parse(ctx, e, name, dir, sql.SQL, combo, parseOpts, stderr)
167172
if failed {
173+
if packageRegion != nil {
174+
packageRegion.End()
175+
}
168176
errored = true
169177
break
170178
}
171179

180+
var region *trace.Region
181+
if debug.Traced {
182+
region = trace.StartRegion(ctx, "codegen")
183+
}
172184
var files map[string]string
173185
var out string
174186
switch {
@@ -184,17 +196,26 @@ func Generate(e Env, dir, filename string, stderr io.Writer) (map[string]string,
184196
default:
185197
panic("missing language backend")
186198
}
199+
if region != nil {
200+
region.End()
201+
}
187202

188203
if err != nil {
189204
fmt.Fprintf(stderr, "# package %s\n", name)
190205
fmt.Fprintf(stderr, "error generating code: %s\n", err)
191206
errored = true
207+
if packageRegion != nil {
208+
packageRegion.End()
209+
}
192210
continue
193211
}
194212
for n, source := range files {
195213
filename := filepath.Join(dir, out, n)
196214
output[filename] = source
197215
}
216+
if packageRegion != nil {
217+
packageRegion.End()
218+
}
198219
}
199220

200221
if errored {
@@ -203,7 +224,10 @@ func Generate(e Env, dir, filename string, stderr io.Writer) (map[string]string,
203224
return output, nil
204225
}
205226

206-
func parse(e Env, name, dir string, sql config.SQL, combo config.CombinedSettings, parserOpts opts.Parser, stderr io.Writer) (*compiler.Result, bool) {
227+
func parse(ctx context.Context, e Env, name, dir string, sql config.SQL, combo config.CombinedSettings, parserOpts opts.Parser, stderr io.Writer) (*compiler.Result, bool) {
228+
if debug.Traced {
229+
defer trace.StartRegion(ctx, "parse").End()
230+
}
207231
c := compiler.NewCompiler(sql, combo)
208232
if err := c.ParseCatalog(sql.Schema); err != nil {
209233
fmt.Fprintf(stderr, "# package %s\n", name)

‎internal/debug/dump.go

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,12 +4,20 @@ import (
44
"os"
55

66
"github.com/davecgh/go-spew/spew"
7+
8+
"github.com/kyleconroy/sqlc/internal/opts"
79
)
810

911
var Active bool
12+
var Traced bool
13+
var Debug opts.Debug
1014

1115
func init() {
1216
Active = os.Getenv("SQLCDEBUG") != ""
17+
if Active {
18+
Debug = opts.DebugFromEnv()
19+
Traced = Debug.Trace != ""
20+
}
1321
}
1422

1523
func Dump(n ...interface{}) {

‎internal/endtoend/endtoend_test.go

Lines changed: 10 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ package main
22

33
import (
44
"bytes"
5+
"context"
56
"os"
67
"path/filepath"
78
"strings"
@@ -15,6 +16,8 @@ import (
1516

1617
func TestExamples(t *testing.T) {
1718
t.Parallel()
19+
ctx := context.Background()
20+
1821
examples, err := filepath.Abs(filepath.Join("..", "..", "examples"))
1922
if err != nil {
2023
t.Fatal(err)
@@ -34,7 +37,7 @@ func TestExamples(t *testing.T) {
3437
t.Parallel()
3538
path := filepath.Join(examples, tc)
3639
var stderr bytes.Buffer
37-
output, err := cmd.Generate(cmd.Env{ExperimentalFeatures: true}, path, "", &stderr)
40+
output, err := cmd.Generate(ctx, cmd.Env{ExperimentalFeatures: true}, path, "", &stderr)
3841
if err != nil {
3942
t.Fatalf("sqlc generate failed: %s", stderr.String())
4043
}
@@ -44,6 +47,7 @@ func TestExamples(t *testing.T) {
4447
}
4548

4649
func BenchmarkExamples(b *testing.B) {
50+
ctx := context.Background()
4751
examples, err := filepath.Abs(filepath.Join("..", "..", "examples"))
4852
if err != nil {
4953
b.Fatal(err)
@@ -61,14 +65,15 @@ func BenchmarkExamples(b *testing.B) {
6165
path := filepath.Join(examples, tc)
6266
for i := 0; i < b.N; i++ {
6367
var stderr bytes.Buffer
64-
cmd.Generate(cmd.Env{ExperimentalFeatures: true}, path, "", &stderr)
68+
cmd.Generate(ctx, cmd.Env{ExperimentalFeatures: true}, path, "", &stderr)
6569
}
6670
})
6771
}
6872
}
6973

7074
func TestReplay(t *testing.T) {
7175
t.Parallel()
76+
ctx := context.Background()
7277
var dirs []string
7378
err := filepath.Walk("testdata", func(path string, info os.FileInfo, err error) error {
7479
if err != nil {
@@ -90,7 +95,7 @@ func TestReplay(t *testing.T) {
9095
path, _ := filepath.Abs(tc)
9196
var stderr bytes.Buffer
9297
expected := expectedStderr(t, path)
93-
output, err := cmd.Generate(cmd.Env{ExperimentalFeatures: true}, path, "", &stderr)
98+
output, err := cmd.Generate(ctx, cmd.Env{ExperimentalFeatures: true}, path, "", &stderr)
9499
if len(expected) == 0 && err != nil {
95100
t.Fatalf("sqlc generate failed: %s", stderr.String())
96101
}
@@ -167,6 +172,7 @@ func expectedStderr(t *testing.T, dir string) string {
167172
}
168173

169174
func BenchmarkReplay(b *testing.B) {
175+
ctx := context.Background()
170176
var dirs []string
171177
err := filepath.Walk("testdata", func(path string, info os.FileInfo, err error) error {
172178
if err != nil {
@@ -187,7 +193,7 @@ func BenchmarkReplay(b *testing.B) {
187193
path, _ := filepath.Abs(tc)
188194
for i := 0; i < b.N; i++ {
189195
var stderr bytes.Buffer
190-
cmd.Generate(cmd.Env{ExperimentalFeatures: true}, path, "", &stderr)
196+
cmd.Generate(ctx, cmd.Env{ExperimentalFeatures: true}, path, "", &stderr)
191197
}
192198
})
193199
}

‎internal/opts/debug.go

Lines changed: 16 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -10,25 +10,35 @@ import (
1010
//
1111
// dumpast: setting dumpast=1 will print the AST of every SQL statement
1212
// dumpcatalog: setting dumpcatalog=1 will print the parsed database schema
13+
// trace: setting trace=<path> will output a trace
1314

1415
type Debug struct {
1516
DumpAST bool
1617
DumpCatalog bool
18+
Trace string
1719
}
1820

19-
func DebugFromEnv() (Debug, error) {
21+
func DebugFromEnv() Debug {
2022
d := Debug{}
2123
val := os.Getenv("SQLCDEBUG")
2224
if val == "" {
23-
return d, nil
25+
return d
2426
}
2527
for _, pair := range strings.Split(val, ",") {
26-
switch strings.TrimSpace(pair) {
27-
case "dumpast=1":
28+
pair = strings.TrimSpace(pair)
29+
switch {
30+
case pair == "dumpast=1":
2831
d.DumpAST = true
29-
case "dumpcatalog=1":
32+
case pair == "dumpcatalog=1":
3033
d.DumpCatalog = true
34+
case strings.HasPrefix(pair, "trace="):
35+
traceName := strings.TrimPrefix(pair, "trace=")
36+
if traceName == "1" {
37+
d.Trace = "trace.out"
38+
} else {
39+
d.Trace = traceName
40+
}
3141
}
3242
}
33-
return d, nil
43+
return d
3444
}

‎internal/tracer/trace.go

Lines changed: 33 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,33 @@
1+
package tracer
2+
3+
import (
4+
"context"
5+
"fmt"
6+
"os"
7+
"runtime/trace"
8+
9+
"github.com/kyleconroy/sqlc/internal/debug"
10+
)
11+
12+
func Start(base context.Context) (context.Context, func(), error) {
13+
if !debug.Traced {
14+
return base, func() {}, nil
15+
}
16+
17+
f, err := os.Create(debug.Debug.Trace)
18+
if err != nil {
19+
return base, func() {}, fmt.Errorf("failed to create trace output file: %v", err)
20+
}
21+
22+
if err := trace.Start(f); err != nil {
23+
return base, func() {}, fmt.Errorf("failed to start trace: %v", err)
24+
}
25+
26+
ctx, task := trace.NewTask(base, "sqlc")
27+
28+
return ctx, func() {
29+
defer f.Close()
30+
defer trace.Stop()
31+
defer task.End()
32+
}, nil
33+
}

0 commit comments

Comments
 (0)