Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

Commit4449931

Browse files
authored
chore: reduce log volume on server startup (#16608)
Addresses#16231.This PR reduces the volume of logs we print after server startup inorder to surface the web UI URL better.Here are the logs after the changes a couple of seconds after startingthe server:<img width="868" alt="Screenshot 2025-02-18 at 16 31 32"src="https://github.com/user-attachments/assets/786dc4b8-7383-48c8-a5c3-a997c01ca915"/>The warning is due to running a development site-less build. It wouldn'tshow in a release build.
1 parent54b09d9 commit4449931

File tree

12 files changed

+207
-61
lines changed

12 files changed

+207
-61
lines changed

‎cli/server.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -938,7 +938,7 @@ func (r *RootCmd) Server(newAPI func(context.Context, *coderd.Options) (*coderd.
938938
notificationReportGenerator:=reports.NewReportGenerator(ctx,logger.Named("notifications.report_generator"),options.Database,options.NotificationsEnqueuer,quartz.NewReal())
939939
defernotificationReportGenerator.Close()
940940
}else {
941-
cliui.Info(inv.Stdout,"Notifications are currently disabled as there are no configured delivery methods. See https://coder.com/docs/admin/monitoring/notifications#delivery-methods for more details.")
941+
logger.Debug(ctx,"notifications are currently disabled as there are no configured delivery methods. See https://coder.com/docs/admin/monitoring/notifications#delivery-methods for more details")
942942
}
943943

944944
// Since errCh only has one buffered slot, all routines

‎cli/server_test.go

Lines changed: 84 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -25,6 +25,7 @@ import (
2525
"runtime"
2626
"strconv"
2727
"strings"
28+
"sync"
2829
"sync/atomic"
2930
"testing"
3031
"time"
@@ -240,6 +241,70 @@ func TestServer(t *testing.T) {
240241
t.Fatalf("expected postgres URL to start with\"postgres://\", got %q",got)
241242
}
242243
})
244+
t.Run("SpammyLogs",func(t*testing.T) {
245+
// The purpose of this test is to ensure we don't show excessive logs when the server starts.
246+
t.Parallel()
247+
inv,cfg:=clitest.New(t,
248+
"server",
249+
"--in-memory",
250+
"--http-address",":0",
251+
"--access-url","http://localhost:3000/",
252+
"--cache-dir",t.TempDir(),
253+
)
254+
stdoutRW:=syncReaderWriter{}
255+
stderrRW:=syncReaderWriter{}
256+
inv.Stdout=io.MultiWriter(os.Stdout,&stdoutRW)
257+
inv.Stderr=io.MultiWriter(os.Stderr,&stderrRW)
258+
clitest.Start(t,inv)
259+
260+
// Wait for startup
261+
_=waitAccessURL(t,cfg)
262+
263+
// Wait a bit for more logs to be printed.
264+
time.Sleep(testutil.WaitShort)
265+
266+
// Lines containing these strings are printed because we're
267+
// running the server with a test config. They wouldn't be
268+
// normally shown to the user, so we'll ignore them.
269+
ignoreLines:= []string{
270+
"isn't externally reachable",
271+
"install.sh will be unavailable",
272+
"telemetry disabled, unable to notify of security issues",
273+
}
274+
275+
countLines:=func(fullOutputstring)int {
276+
terminalWidth:=80
277+
linesByNewline:=strings.Split(fullOutput,"\n")
278+
countByWidth:=0
279+
lineLoop:
280+
for_,line:=rangelinesByNewline {
281+
for_,ignoreLine:=rangeignoreLines {
282+
ifstrings.Contains(line,ignoreLine) {
283+
continue lineLoop
284+
}
285+
}
286+
ifline=="" {
287+
// Empty lines take up one line.
288+
countByWidth++
289+
}else {
290+
countByWidth+= (len(line)+terminalWidth-1)/terminalWidth
291+
}
292+
}
293+
returncountByWidth
294+
}
295+
296+
stdout,err:=io.ReadAll(&stdoutRW)
297+
iferr!=nil {
298+
t.Fatalf("failed to read stdout: %v",err)
299+
}
300+
stderr,err:=io.ReadAll(&stderrRW)
301+
iferr!=nil {
302+
t.Fatalf("failed to read stderr: %v",err)
303+
}
304+
305+
numLines:=countLines(string(stdout))+countLines(string(stderr))
306+
require.Less(t,numLines,20)
307+
})
243308

244309
// Validate that a warning is printed that it may not be externally
245310
// reachable.
@@ -2140,3 +2205,22 @@ func mockTelemetryServer(t *testing.T) (*url.URL, chan *telemetry.Deployment, ch
21402205

21412206
returnserverURL,deployment,snapshot
21422207
}
2208+
2209+
// syncWriter provides a thread-safe io.ReadWriter implementation
2210+
typesyncReaderWriterstruct {
2211+
buf bytes.Buffer
2212+
mu sync.Mutex
2213+
}
2214+
2215+
func (w*syncReaderWriter)Write(p []byte) (nint,errerror) {
2216+
w.mu.Lock()
2217+
deferw.mu.Unlock()
2218+
returnw.buf.Write(p)
2219+
}
2220+
2221+
func (w*syncReaderWriter)Read(p []byte) (nint,errerror) {
2222+
w.mu.Lock()
2223+
deferw.mu.Unlock()
2224+
2225+
returnw.buf.Read(p)
2226+
}

‎coderd/cryptokeys/rotate.go

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -152,7 +152,7 @@ func (k *rotator) rotateKeys(ctx context.Context) error {
152152
}
153153
}
154154
ifvalidKeys==0 {
155-
k.logger.Info(ctx,"no valid keys detected, inserting new key",
155+
k.logger.Debug(ctx,"no valid keys detected, inserting new key",
156156
slog.F("feature",feature),
157157
)
158158
_,err:=k.insertNewKey(ctx,tx,feature,now)
@@ -194,7 +194,7 @@ func (k *rotator) insertNewKey(ctx context.Context, tx database.Store, feature d
194194
return database.CryptoKey{},xerrors.Errorf("inserting new key: %w",err)
195195
}
196196

197-
k.logger.Info(ctx,"inserted new key for feature",slog.F("feature",feature))
197+
k.logger.Debug(ctx,"inserted new key for feature",slog.F("feature",feature))
198198
returnnewKey,nil
199199
}
200200

‎coderd/database/dbpurge/dbpurge.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -63,7 +63,7 @@ func New(ctx context.Context, logger slog.Logger, db database.Store, clk quartz.
6363
returnxerrors.Errorf("failed to delete old notification messages: %w",err)
6464
}
6565

66-
logger.Info(ctx,"purged old database entries",slog.F("duration",clk.Since(start)))
66+
logger.Debug(ctx,"purged old database entries",slog.F("duration",clk.Since(start)))
6767

6868
returnnil
6969
},database.DefaultTXOptions().WithID("db_purge"));err!=nil {

‎enterprise/cli/provisionerdaemonstart.go

Lines changed: 5 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -236,10 +236,11 @@ func (r *RootCmd) provisionerDaemonStart() *serpent.Command {
236236
ProvisionerKey:provisionerKey,
237237
})
238238
},&provisionerd.Options{
239-
Logger:logger,
240-
UpdateInterval:500*time.Millisecond,
241-
Connector:connector,
242-
Metrics:metrics,
239+
Logger:logger,
240+
UpdateInterval:500*time.Millisecond,
241+
Connector:connector,
242+
Metrics:metrics,
243+
ExternalProvisioner:true,
243244
})
244245

245246
waitForProvisionerJobs:=false

‎provisioner/terraform/install.go

Lines changed: 38 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -2,8 +2,10 @@ package terraform
22

33
import (
44
"context"
5+
"fmt"
56
"os"
67
"path/filepath"
8+
"sync/atomic"
79
"time"
810

911
"github.com/gofrs/flock"
@@ -30,7 +32,9 @@ var (
3032

3133
// Install implements a thread-safe, idempotent Terraform Install
3234
// operation.
33-
funcInstall(ctx context.Context,log slog.Logger,dirstring,wantVersion*version.Version) (string,error) {
35+
//
36+
//nolint:revive // verbose is a control flag that controls the verbosity of the log output.
37+
funcInstall(ctx context.Context,log slog.Logger,verbosebool,dirstring,wantVersion*version.Version) (string,error) {
3438
err:=os.MkdirAll(dir,0o750)
3539
iferr!=nil {
3640
return"",err
@@ -64,13 +68,37 @@ func Install(ctx context.Context, log slog.Logger, dir string, wantVersion *vers
6468
Version:TerraformVersion,
6569
}
6670
installer.SetLogger(slog.Stdlib(ctx,log,slog.LevelDebug))
67-
log.Debug(
68-
ctx,
69-
"installing terraform",
71+
72+
logInstall:=log.Debug
73+
ifverbose {
74+
logInstall=log.Info
75+
}
76+
77+
logInstall(ctx,"installing terraform",
7078
slog.F("prev_version",hasVersionStr),
7179
slog.F("dir",dir),
72-
slog.F("version",TerraformVersion),
73-
)
80+
slog.F("version",TerraformVersion))
81+
82+
prolongedInstall:= atomic.Bool{}
83+
prolongedInstallCtx,prolongedInstallCancel:=context.WithCancel(ctx)
84+
gofunc() {
85+
seconds:=15
86+
select {
87+
case<-time.After(time.Duration(seconds)*time.Second):
88+
prolongedInstall.Store(true)
89+
// We always want to log this at the info level.
90+
log.Info(
91+
prolongedInstallCtx,
92+
fmt.Sprintf("terraform installation is taking longer than %d seconds, still in progress",seconds),
93+
slog.F("prev_version",hasVersionStr),
94+
slog.F("dir",dir),
95+
slog.F("version",TerraformVersion),
96+
)
97+
case<-prolongedInstallCtx.Done():
98+
return
99+
}
100+
}()
101+
deferprolongedInstallCancel()
74102

75103
path,err:=installer.Install(ctx)
76104
iferr!=nil {
@@ -83,5 +111,9 @@ func Install(ctx context.Context, log slog.Logger, dir string, wantVersion *vers
83111
return"",xerrors.Errorf("%s should be %s",path,binPath)
84112
}
85113

114+
ifprolongedInstall.Load() {
115+
log.Info(ctx,"terraform installation complete")
116+
}
117+
86118
returnpath,nil
87119
}

‎provisioner/terraform/install_test.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -40,7 +40,7 @@ func TestInstall(t *testing.T) {
4040
wg.Add(1)
4141
gofunc() {
4242
deferwg.Done()
43-
p,err:=terraform.Install(ctx,log,dir,version)
43+
p,err:=terraform.Install(ctx,log,false,dir,version)
4444
assert.NoError(t,err)
4545
paths<-p
4646
}()

‎provisioner/terraform/serve.go

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

33
import (
44
"context"
5+
"errors"
56
"path/filepath"
67
"sync"
78
"time"
89

910
"github.com/cli/safeexec"
11+
"github.com/hashicorp/go-version"
1012
semconv"go.opentelemetry.io/otel/semconv/v1.14.0"
1113
"go.opentelemetry.io/otel/trace"
1214
"golang.org/x/xerrors"
@@ -41,10 +43,15 @@ type ServeOptions struct {
4143
ExitTimeout time.Duration
4244
}
4345

44-
funcabsoluteBinaryPath(ctx context.Context,logger slog.Logger) (string,error) {
46+
typesystemBinaryDetailsstruct {
47+
absolutePathstring
48+
version*version.Version
49+
}
50+
51+
funcsystemBinary(ctx context.Context) (*systemBinaryDetails,error) {
4552
binaryPath,err:=safeexec.LookPath("terraform")
4653
iferr!=nil {
47-
return"",xerrors.Errorf("Terraform binary not found: %w",err)
54+
returnnil,xerrors.Errorf("Terraform binary not found: %w",err)
4855
}
4956

5057
// If the "coder" binary is in the same directory as
@@ -54,59 +61,68 @@ func absoluteBinaryPath(ctx context.Context, logger slog.Logger) (string, error)
5461
// to execute this properly!
5562
absoluteBinary,err:=filepath.Abs(binaryPath)
5663
iferr!=nil {
57-
return"",xerrors.Errorf("Terraform binary absolute path not found: %w",err)
64+
returnnil,xerrors.Errorf("Terraform binary absolute path not found: %w",err)
5865
}
5966

6067
// Checking the installed version of Terraform.
6168
installedVersion,err:=versionFromBinaryPath(ctx,absoluteBinary)
6269
iferr!=nil {
63-
return"",xerrors.Errorf("Terraform binary get version failed: %w",err)
70+
returnnil,xerrors.Errorf("Terraform binary get version failed: %w",err)
6471
}
6572

66-
logger.Info(ctx,"detected terraform version",
67-
slog.F("installed_version",installedVersion.String()),
68-
slog.F("min_version",minTerraformVersion.String()),
69-
slog.F("max_version",maxTerraformVersion.String()))
70-
71-
ifinstalledVersion.LessThan(minTerraformVersion) {
72-
logger.Warn(ctx,"installed terraform version too old, will download known good version to cache")
73-
return"",terraformMinorVersionMismatch
73+
details:=&systemBinaryDetails{
74+
absolutePath:absoluteBinary,
75+
version:installedVersion,
7476
}
7577

76-
// Warn if the installed version is newer than what we've decided is the max.
77-
// We used to ignore it and download our own version but this makes it easier
78-
// to test out newer versions of Terraform.
79-
ifinstalledVersion.GreaterThanOrEqual(maxTerraformVersion) {
80-
logger.Warn(ctx,"installed terraform version newer than expected, you may experience bugs",
81-
slog.F("installed_version",installedVersion.String()),
82-
slog.F("max_version",maxTerraformVersion.String()))
78+
ifinstalledVersion.LessThan(minTerraformVersion) {
79+
returndetails,terraformMinorVersionMismatch
8380
}
8481

85-
returnabsoluteBinary,nil
82+
returndetails,nil
8683
}
8784

8885
// Serve starts a dRPC server on the provided transport speaking Terraform provisioner.
8986
funcServe(ctx context.Context,options*ServeOptions)error {
9087
ifoptions.BinaryPath=="" {
91-
absoluteBinary,err:=absoluteBinaryPath(ctx,options.Logger)
88+
binaryDetails,err:=systemBinary(ctx)
9289
iferr!=nil {
9390
// This is an early exit to prevent extra execution in case the context is canceled.
9491
// It generally happens in unit tests since this method is asynchronous and
9592
// the unit test kills the app before this is complete.
96-
ifxerrors.Is(err,context.Canceled) {
97-
returnxerrors.Errorf("absolute binary context canceled: %w",err)
93+
iferrors.Is(err,context.Canceled) {
94+
returnxerrors.Errorf("system binary context canceled: %w",err)
9895
}
9996

100-
options.Logger.Warn(ctx,"no usable terraform binary found, downloading to cache dir",
101-
slog.F("terraform_version",TerraformVersion.String()),
102-
slog.F("cache_dir",options.CachePath))
103-
binPath,err:=Install(ctx,options.Logger,options.CachePath,TerraformVersion)
97+
iferrors.Is(err,terraformMinorVersionMismatch) {
98+
options.Logger.Warn(ctx,"installed terraform version too old, will download known good version to cache, or use a previously cached version",
99+
slog.F("installed_version",binaryDetails.version.String()),
100+
slog.F("min_version",minTerraformVersion.String()))
101+
}
102+
103+
binPath,err:=Install(ctx,options.Logger,options.ExternalProvisioner,options.CachePath,TerraformVersion)
104104
iferr!=nil {
105105
returnxerrors.Errorf("install terraform: %w",err)
106106
}
107107
options.BinaryPath=binPath
108108
}else {
109-
options.BinaryPath=absoluteBinary
109+
logVersion:=options.Logger.Debug
110+
ifoptions.ExternalProvisioner {
111+
logVersion=options.Logger.Info
112+
}
113+
logVersion(ctx,"detected terraform version",
114+
slog.F("installed_version",binaryDetails.version.String()),
115+
slog.F("min_version",minTerraformVersion.String()),
116+
slog.F("max_version",maxTerraformVersion.String()))
117+
// Warn if the installed version is newer than what we've decided is the max.
118+
// We used to ignore it and download our own version but this makes it easier
119+
// to test out newer versions of Terraform.
120+
ifbinaryDetails.version.GreaterThanOrEqual(maxTerraformVersion) {
121+
options.Logger.Warn(ctx,"installed terraform version newer than expected, you may experience bugs",
122+
slog.F("installed_version",binaryDetails.version.String()),
123+
slog.F("max_version",maxTerraformVersion.String()))
124+
}
125+
options.BinaryPath=binaryDetails.absolutePath
110126
}
111127
}
112128
ifoptions.Tracer==nil {

‎provisioner/terraform/serve_internal_test.go

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -54,7 +54,6 @@ func Test_absoluteBinaryPath(t *testing.T) {
5454
t.Skip("Dummy terraform executable on Windows requires sh which isn't very practical.")
5555
}
5656

57-
log:=testutil.Logger(t)
5857
// Create a temp dir with the binary
5958
tempDir:=t.TempDir()
6059
terraformBinaryOutput:=fmt.Sprintf(`#!/bin/sh
@@ -85,11 +84,12 @@ func Test_absoluteBinaryPath(t *testing.T) {
8584
}
8685

8786
ctx:=testutil.Context(t,testutil.WaitShort)
88-
actualAbsoluteBinary,actualErr:=absoluteBinaryPath(ctx,log)
87+
actualBinaryDetails,actualErr:=systemBinary(ctx)
8988

90-
require.Equal(t,expectedAbsoluteBinary,actualAbsoluteBinary)
9189
iftt.expectedErr==nil {
9290
require.NoError(t,actualErr)
91+
require.Equal(t,expectedAbsoluteBinary,actualBinaryDetails.absolutePath)
92+
require.Equal(t,tt.terraformVersion,actualBinaryDetails.version.String())
9393
}else {
9494
require.EqualError(t,actualErr,tt.expectedErr.Error())
9595
}

0 commit comments

Comments
 (0)
[8]ページ先頭
©2009-2025 Movatter.jp