Skip to content

Commit 70bef8d

Browse files
rafissrafiss
authored
Merge pull request #118 from rafiss/better-testserver-logging
testserver: add more informative error and log messages
2 parents 5baee17 + 0dc5d66 commit 70bef8d

File tree

2 files changed

+35
-29
lines changed

2 files changed

+35
-29
lines changed

‎testserver/tenant.go‎

Lines changed: 16 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -82,26 +82,28 @@ func (ts *testServerImpl) NewTenantServer(proxy bool) (TestServer, error) {
8282
// Create tenant client certificate.
8383
{"mt", "cert", "create-tenant-client", fmt.Sprint(tenantID)},
8484
} {
85-
if err := exec.Command(cockroachBinary, append(args, certArgs...)...).Run(); err != nil {
86-
return nil, fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
85+
createCertCmd := exec.Command(cockroachBinary, append(args, certArgs...)...)
86+
log.Printf("%s executing: %s", tenantserverMessagePrefix, createCertCmd)
87+
if err := createCertCmd.Run(); err != nil {
88+
return nil, fmt.Errorf("%s command %s failed: %w", tenantserverMessagePrefix, createCertCmd, err)
8789
}
8890
}
8991
}
9092
// Create a new tenant.
9193
if err := ts.WaitForInit(); err != nil {
92-
return nil, fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
94+
return nil, fmt.Errorf("%s WaitForInit failed: %w", tenantserverMessagePrefix, err)
9395
}
9496
pgURL := ts.PGURL()
9597
if pgURL == nil {
9698
return nil, fmt.Errorf("%s: url not found", tenantserverMessagePrefix)
9799
}
98100
db, err := sql.Open("postgres", pgURL.String())
99101
if err != nil {
100-
return nil, fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
102+
return nil, fmt.Errorf("%s cannot open connection: %w", tenantserverMessagePrefix, err)
101103
}
102104
defer db.Close()
103105
if _, err := db.Exec(fmt.Sprintf("SELECT crdb_internal.create_tenant(%d)", tenantID)); err != nil {
104-
return nil, fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
106+
return nil, fmt.Errorf("%s cannot create tenant: %w", tenantserverMessagePrefix, err)
105107
}
106108

107109
// TODO(asubiotto): We should pass ":0" as the sql addr to push port
@@ -112,13 +114,13 @@ func (ts *testServerImpl) NewTenantServer(proxy bool) (TestServer, error) {
112114
addr := func() (string, error) {
113115
l, err := net.Listen("tcp", ":0")
114116
if err != nil {
115-
return "", fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
117+
return "", fmt.Errorf("%s cannot listen on a port: %w", tenantserverMessagePrefix, err)
116118
}
117119
// Use localhost because of certificate validation issues otherwise
118120
// (something about IP SANs).
119121
addr := "localhost:" + strconv.Itoa(l.Addr().(*net.TCPAddr).Port)
120122
if err := l.Close(); err != nil {
121-
return "", fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
123+
return "", fmt.Errorf("%s cannot close listener: %w", tenantserverMessagePrefix, err)
122124
}
123125
return addr, nil
124126
}
@@ -156,8 +158,9 @@ func (ts *testServerImpl) NewTenantServer(proxy bool) (TestServer, error) {
156158
"--skip-verify",
157159
}
158160
cmd := exec.Command(cockroachBinary, args...)
161+
log.Printf("%s executing: %s", tenantserverMessagePrefix, cmd)
159162
if err := cmd.Start(); err != nil {
160-
return "", fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
163+
return "", fmt.Errorf("%s command %s failed: %w", tenantserverMessagePrefix, cmd, err)
161164
}
162165
if cmd.Process != nil {
163166
log.Printf("%s: process %d started: %s", tenantserverMessagePrefix, cmd.Process.Pid,
@@ -168,7 +171,7 @@ func (ts *testServerImpl) NewTenantServer(proxy bool) (TestServer, error) {
168171
return ts.proxyAddr, nil
169172
}()
170173
if err != nil {
171-
return nil, fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
174+
return nil, err
172175
}
173176

174177
args := []string{
@@ -204,15 +207,15 @@ func (ts *testServerImpl) NewTenantServer(proxy bool) (TestServer, error) {
204207

205208
tenant.setPGURL(&tenantURL)
206209
if err := tenant.Start(); err != nil {
207-
return nil, fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
210+
return nil, fmt.Errorf("%s Start failed : %w", tenantserverMessagePrefix, err)
208211
}
209212
if err := tenant.WaitForInit(); err != nil {
210-
return nil, fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
213+
return nil, fmt.Errorf("%s WaitForInit failed: %w", tenantserverMessagePrefix, err)
211214
}
212215

213216
tenantDB, err := sql.Open("postgres", tenantURL.String())
214217
if err != nil {
215-
return nil, fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
218+
return nil, fmt.Errorf("%s cannot open connection: %w", tenantserverMessagePrefix, err)
216219
}
217220
defer tenantDB.Close()
218221

@@ -228,7 +231,7 @@ func (ts *testServerImpl) NewTenantServer(proxy bool) (TestServer, error) {
228231
if rootPassword != "" {
229232
// Allow root to login via password.
230233
if _, err := tenantDB.Exec(`ALTER USER $1 WITH PASSWORD $2`, "root", rootPassword); err != nil {
231-
return nil, fmt.Errorf("%s: %w", tenantserverMessagePrefix, err)
234+
return nil, fmt.Errorf("%s cannot set password: %w", tenantserverMessagePrefix, err)
232235
}
233236

234237
// NB: need the lock since *tenantURL is owned by `tenant`.

‎testserver/testserver.go‎

Lines changed: 19 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -340,8 +340,10 @@ func NewTestServer(opts ...TestServerOpt) (TestServer, error) {
340340
// Create cert and key pair for the root user (SQL client).
341341
{"cert", "create-client", "root"},
342342
} {
343-
if err := exec.Command(cockroachBinary, append(args, certArgs...)...).Run(); err != nil {
344-
return nil, fmt.Errorf("%s: %w", testserverMessagePrefix, err)
343+
createCertCmd := exec.Command(cockroachBinary, append(args, certArgs...)...)
344+
log.Printf("%s executing: %s", testserverMessagePrefix, createCertCmd)
345+
if err := createCertCmd.Run(); err != nil {
346+
return nil, fmt.Errorf("%s command %s failed: %w", testserverMessagePrefix, createCertCmd, err)
345347
}
346348
}
347349
secureOpt = "--certs-dir=" + certsDir
@@ -353,17 +355,17 @@ func NewTestServer(opts ...TestServerOpt) (TestServer, error) {
353355
versionCmd := exec.Command(cockroachBinary, "version")
354356
versionOutput, err := versionCmd.CombinedOutput()
355357
if err != nil {
356-
return nil, fmt.Errorf("%s: %w", testserverMessagePrefix, err)
358+
return nil, fmt.Errorf("%s command %s failed: %w", testserverMessagePrefix, versionCmd, err)
357359
}
358360
reader := bufio.NewReader(bytes.NewReader(versionOutput))
359361
versionLine, err := reader.ReadString('\n')
360362
if err != nil {
361-
return nil, fmt.Errorf("%s: %w", testserverMessagePrefix, err)
363+
return nil, fmt.Errorf("%s failed to read version: %w", testserverMessagePrefix, err)
362364
}
363365
versionLineTokens := strings.Fields(versionLine)
364366
v, err := version.Parse(versionLineTokens[2])
365367
if err != nil {
366-
return nil, fmt.Errorf("%s: %w", testserverMessagePrefix, err)
368+
return nil, fmt.Errorf("%s failed to parse version: %w", testserverMessagePrefix, err)
367369
}
368370
startCmd := "start-single-node"
369371
if !v.AtLeast(version.MustParse("v19.2.0-alpha")) {
@@ -402,15 +404,15 @@ func NewTestServer(opts ...TestServerOpt) (TestServer, error) {
402404
ts.pgURL.set = make(chan struct{})
403405

404406
if err := ts.Start(); err != nil {
405-
return nil, fmt.Errorf("%s: %w", testserverMessagePrefix, err)
407+
return nil, fmt.Errorf("%s Start failed: %w", testserverMessagePrefix, err)
406408
}
407409

408410
if ts.PGURL() == nil {
409411
return nil, fmt.Errorf("%s: url not found", testserverMessagePrefix)
410412
}
411413

412414
if err := ts.WaitForInit(); err != nil {
413-
return nil, fmt.Errorf("%s: %w", testserverMessagePrefix, err)
415+
return nil, fmt.Errorf("%s WaitForInit failed: %w", testserverMessagePrefix, err)
414416
}
415417

416418
return ts, nil
@@ -556,6 +558,7 @@ func (ts *testServerImpl) Start() error {
556558
ts.cmd.Env = append(ts.cmd.Env, k+"="+v)
557559
}
558560

561+
log.Printf("executing: %s", ts.cmd)
559562
err := ts.cmd.Start()
560563
if ts.cmd.Process != nil {
561564
log.Printf("process %d started: %s", ts.cmd.Process.Pid, strings.Join(ts.cmdArgs, " "))
@@ -573,28 +576,28 @@ func (ts *testServerImpl) Start() error {
573576
ts.state = stateFailed
574577
ts.mu.Unlock()
575578

576-
return fmt.Errorf("failure starting process: %w", err)
579+
return fmt.Errorf("command %s failed: %w", ts.cmd, err)
577580
}
578581

579582
go func() {
580583
err := ts.cmd.Wait()
581584

582-
if err := ts.stdoutBuf.Close(); err != nil {
583-
log.Printf("%s: failed to close stdout: %v", testserverMessagePrefix, err)
585+
if closeErr := ts.stdoutBuf.Close(); closeErr != nil {
586+
log.Printf("%s: failed to close stdout: %v", testserverMessagePrefix, closeErr)
584587
}
585-
if err := ts.stderrBuf.Close(); err != nil {
586-
log.Printf("%s: failed to close stderr: %v", testserverMessagePrefix, err)
588+
if closeErr := ts.stderrBuf.Close(); closeErr != nil {
589+
log.Printf("%s: failed to close stderr: %v", testserverMessagePrefix, closeErr)
587590
}
588591

589592
ps := ts.cmd.ProcessState
590593
sy := ps.Sys().(syscall.WaitStatus)
591594

592-
log.Printf("%s: Process %d exited with status %d: %v",
595+
log.Printf("%s: command %s exited with status %d: %v",
593596
testserverMessagePrefix,
594-
ps.Pid(),
597+
ts.cmd,
595598
sy.ExitStatus(),
596599
err)
597-
log.Print(ps.String())
600+
log.Printf("%s process state: %s", testserverMessagePrefix, ps.String())
598601

599602
ts.mu.Lock()
600603
if sy.ExitStatus() == 0 {
@@ -608,7 +611,7 @@ func (ts *testServerImpl) Start() error {
608611
if ts.pgURL.u == nil {
609612
go func() {
610613
if err := ts.pollListeningURLFile(); err != nil {
611-
log.Printf("%s: %v", testserverMessagePrefix, err)
614+
log.Printf("%s failed to poll listening URL file: %v", testserverMessagePrefix, err)
612615
close(ts.pgURL.set)
613616
ts.Stop()
614617
}

0 commit comments

Comments
 (0)