From 188f268024f8298d8a4f366b3dadf7e04f0afe16 Mon Sep 17 00:00:00 2001 From: Eno Compton Date: Tue, 12 Jul 2022 07:35:39 -0600 Subject: [PATCH] feat: add support for structured logs This is a port of https://github.com/GoogleCloudPlatform/cloudsql-proxy/pull/1246 --- alloydb/alloydb.go | 10 ++++ cmd/root.go | 97 ++++++++++++++++++++++------------- cmd/root_test.go | 7 +++ go.mod | 1 + go.sum | 6 +++ internal/log/log.go | 98 ++++++++++++++++++++++++++++++++++++ internal/proxy/proxy.go | 39 +++++++------- internal/proxy/proxy_test.go | 31 ++++++------ 8 files changed, 220 insertions(+), 69 deletions(-) create mode 100644 internal/log/log.go diff --git a/alloydb/alloydb.go b/alloydb/alloydb.go index d9168f1c..6654fd12 100644 --- a/alloydb/alloydb.go +++ b/alloydb/alloydb.go @@ -29,3 +29,13 @@ type Dialer interface { io.Closer } + +// Logger is the interface used throughout the project for logging. +type Logger interface { + // Debugf is for reporting additional information about internal operations. + Debugf(format string, args ...interface{}) + // Infof is for reporting informational messages. + Infof(format string, args ...interface{}) + // Errorf is for reporting errors. + Errorf(format string, args ...interface{}) +} diff --git a/cmd/root.go b/cmd/root.go index cd9650fe..75e8dd2c 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -32,6 +32,7 @@ import ( "contrib.go.opencensus.io/exporter/prometheus" "contrib.go.opencensus.io/exporter/stackdriver" "github.com/GoogleCloudPlatform/alloydb-auth-proxy/alloydb" + "github.com/GoogleCloudPlatform/alloydb-auth-proxy/internal/log" "github.com/GoogleCloudPlatform/alloydb-auth-proxy/internal/proxy" "github.com/spf13/cobra" "go.opencensus.io/trace" @@ -76,8 +77,11 @@ func Execute() { // Command represents an invocation of the AlloyDB Auth Proxy. type Command struct { *cobra.Command - conf *proxy.Config + conf *proxy.Config + logger alloydb.Logger + dialer alloydb.Dialer + cleanup func() error disableTraces bool telemetryTracingSampleRate int disableMetrics bool @@ -88,25 +92,25 @@ type Command struct { } // Option is a function that configures a Command. -type Option func(*proxy.Config) +type Option func(*Command) + +// WithLogger overrides the default logger. +func WithLogger(l alloydb.Logger) Option { + return func(c *Command) { + c.logger = l + } +} // WithDialer configures the Command to use the provided dialer to connect to // AlloyDB instances. func WithDialer(d alloydb.Dialer) Option { - return func(c *proxy.Config) { - c.Dialer = d + return func(c *Command) { + c.dialer = d } } // NewCommand returns a Command object representing an invocation of the proxy. func NewCommand(opts ...Option) *Command { - c := &Command{ - conf: &proxy.Config{}, - } - for _, o := range opts { - o(c.conf) - } - cmd := &cobra.Command{ Use: "alloydb-auth-proxy instance_uri...", Version: versionString, @@ -115,19 +119,38 @@ func NewCommand(opts ...Option) *Command { connecting to AlloyDB instances. It listens on a local port and forwards connections to your instance's IP address, providing a secure connection without having to manage any client SSL certificates.`, - Args: func(cmd *cobra.Command, args []string) error { - err := parseConfig(cmd, c.conf, args) - if err != nil { - return err - } - // The arguments are parsed. Usage is no longer needed. - cmd.SilenceUsage = true - return nil - }, - RunE: func(*cobra.Command, []string) error { - return runSignalWrapper(c) + } + + logger := log.NewStdLogger(os.Stdout, os.Stderr) + c := &Command{ + Command: cmd, + logger: logger, + cleanup: func() error { return nil }, + conf: &proxy.Config{ + UserAgent: userAgent, }, } + for _, o := range opts { + o(c) + } + + cmd.Args = func(cmd *cobra.Command, args []string) error { + // Handle logger separately from config + if c.conf.StructuredLogs { + c.logger, c.cleanup = log.NewStructuredLogger() + } + err := parseConfig(c, c.conf, args) + if err != nil { + return err + } + // The arguments are parsed. Usage is no longer needed. + cmd.SilenceUsage = true + // Errors will be handled by logging from here on. + cmd.SilenceErrors = true + return nil + } + + cmd.RunE = func(*cobra.Command, []string) error { return runSignalWrapper(c) } // Global-only flags cmd.PersistentFlags().StringVarP(&c.conf.Token, "token", "t", "", @@ -136,6 +159,8 @@ without having to manage any client SSL certificates.`, "Path to a service account key to use for authentication.") cmd.PersistentFlags().BoolVarP(&c.conf.GcloudAuth, "gcloud-auth", "g", false, "Use gcloud's user configuration to retrieve a token for authentication.") + cmd.PersistentFlags().BoolVarP(&c.conf.StructuredLogs, "structured-logs", "l", false, + "Enable structured logs using the LogEntry format") cmd.PersistentFlags().Uint64Var(&c.conf.MaxConnections, "max-connections", 0, `Limits the number of connections by refusing any additional connections. When this flag is not set, there is no limit.`) @@ -168,18 +193,15 @@ the maximum time has passed. Defaults to 0s.`) cmd.PersistentFlags().StringVarP(&c.conf.UnixSocket, "unix-socket", "u", "", `Enables Unix sockets for all listeners using the provided directory.`) - c.Command = cmd return c } -func parseConfig(cmd *cobra.Command, conf *proxy.Config, args []string) error { +func parseConfig(cmd *Command, conf *proxy.Config, args []string) error { // If no instance connection names were provided, error. if len(args) == 0 { return newBadCommandError("missing instance uri (e.g., /projects/$PROJECTS/locations/$LOCTION/clusters/$CLUSTER/instances/$INSTANCES)") } - conf.UserAgent = userAgent - userHasSet := func(f string) bool { return cmd.PersistentFlags().Lookup(f).Changed } @@ -210,13 +232,13 @@ func parseConfig(cmd *cobra.Command, conf *proxy.Config, args []string) error { } if !userHasSet("telemetry-project") && userHasSet("telemetry-prefix") { - cmd.Println("Ignoring telementry-prefix as telemetry-project was not set") + cmd.logger.Infof("Ignoring telementry-prefix as telemetry-project was not set") } if !userHasSet("telemetry-project") && userHasSet("disable-metrics") { - cmd.Println("Ignoring disable-metrics as telemetry-project was not set") + cmd.logger.Infof("Ignoring disable-metrics as telemetry-project was not set") } if !userHasSet("telemetry-project") && userHasSet("disable-traces") { - cmd.Println("Ignoring disable-traces as telemetry-project was not set") + cmd.logger.Infof("Ignoring disable-traces as telemetry-project was not set") } var ics []proxy.InstanceConnConfig @@ -288,6 +310,7 @@ func parseConfig(cmd *cobra.Command, conf *proxy.Config, args []string) error { // runSignalWrapper watches for SIGTERM and SIGINT and interupts execution if necessary. func runSignalWrapper(cmd *Command) error { + defer cmd.cleanup() ctx, cancel := context.WithCancel(cmd.Context()) defer cancel() @@ -340,7 +363,7 @@ func runSignalWrapper(cmd *Command) error { // Give the HTTP server a second to shutdown cleanly. ctx2, _ := context.WithTimeout(context.Background(), time.Second) if err := server.Shutdown(ctx2); err != nil { - cmd.Printf("failed to shutdown Prometheus HTTP server: %v\n", err) + cmd.logger.Errorf("failed to shutdown Prometheus HTTP server: %v\n", err) } } }() @@ -378,7 +401,7 @@ func runSignalWrapper(cmd *Command) error { startCh := make(chan *proxy.Client) go func() { defer close(startCh) - p, err := proxy.NewClient(ctx, cmd.Command, cmd.conf) + p, err := proxy.NewClient(ctx, cmd.dialer, cmd.logger, cmd.conf) if err != nil { shutdownCh <- fmt.Errorf("unable to start: %v", err) return @@ -389,13 +412,15 @@ func runSignalWrapper(cmd *Command) error { var p *proxy.Client select { case err := <-shutdownCh: + cmd.logger.Errorf("The proxy has encountered a terminal error: %v", err) return err case p = <-startCh: } - cmd.Println("The proxy has started successfully and is ready for new connections!") + cmd.logger.Infof("The proxy has started successfully and is ready for new connections!") + defer p.Close() defer func() { if cErr := p.Close(); cErr != nil { - cmd.PrintErrf("The proxy failed to close cleanly: %v\n", cErr) + cmd.logger.Errorf("error during shutdown: %v", cErr) } }() @@ -406,11 +431,11 @@ func runSignalWrapper(cmd *Command) error { err := <-shutdownCh switch { case errors.Is(err, errSigInt): - cmd.PrintErrln("SIGINT signal received. Shutting down...") + cmd.logger.Errorf("SIGINT signal received. Shutting down...") case errors.Is(err, errSigTerm): - cmd.PrintErrln("SIGTERM signal received. Shutting down...") + cmd.logger.Errorf("SIGTERM signal received. Shutting down...") default: - cmd.PrintErrf("The proxy has encountered a terminal error: %v\n", err) + cmd.logger.Errorf("The proxy has encountered a terminal error: %v", err) } return err } diff --git a/cmd/root_test.go b/cmd/root_test.go index de56747e..741b2680 100644 --- a/cmd/root_test.go +++ b/cmd/root_test.go @@ -177,6 +177,13 @@ func TestNewCommandArguments(t *testing.T) { WaitOnClose: 10 * time.Second, }), }, + { + desc: "enabling structured logging", + args: []string{"--structured-logs", "/projects/proj/locations/region/clusters/clust/instances/inst"}, + want: withDefaults(&proxy.Config{ + StructuredLogs: true, + }), + }, } for _, tc := range tcs { diff --git a/go.mod b/go.mod index c60e0d53..8cf21f0a 100644 --- a/go.mod +++ b/go.mod @@ -10,6 +10,7 @@ require ( github.com/lib/pq v1.10.5 // indirect github.com/spf13/cobra v1.5.0 go.opencensus.io v0.23.0 + go.uber.org/zap v1.21.0 // indirect golang.org/x/net v0.0.0-20220517181318-183a9ca12b87 // indirect golang.org/x/oauth2 v0.0.0-20220622183110-fd043fe589d2 golang.org/x/sys v0.0.0-20220708085239-5a0f0661e09d diff --git a/go.sum b/go.sum index 21f2ab6f..0a728ed4 100644 --- a/go.sum +++ b/go.sum @@ -148,6 +148,7 @@ github.com/aws/aws-sdk-go v1.43.11/go.mod h1:y4AeaBuwd2Lk+GepC1E9v0qOiTws0MIWAX4 github.com/aws/aws-sdk-go v1.43.31 h1:yJZIr8nMV1hXjAvvOLUFqZRJcHV7udPQBfhJqawDzI0= github.com/aws/aws-sdk-go v1.43.31/go.mod h1:y4AeaBuwd2Lk+GepC1E9v0qOiTws0MIWAX4oIKwKHZo= github.com/benbjohnson/clock v1.0.3/go.mod h1:bGMdMPoPVvcYyt1gHDf4J2KE153Yf9BuiUKYMaxlTDM= +github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA= github.com/beorn7/perks v0.0.0-20160804104726-4c0e84591b9a/go.mod h1:Dwedo/Wpr24TaqPxmxbtue+5NUziq4I4S80YR8gNf3Q= github.com/beorn7/perks v0.0.0-20180321164747-3a771d992973/go.mod h1:Dwedo/Wpr24TaqPxmxbtue+5NUziq4I4S80YR8gNf3Q= github.com/beorn7/perks v1.0.0/go.mod h1:KWe93zE9D1o94FZ5RNwFwVgaQK1VOXiVxmqh+CedLV8= @@ -1183,19 +1184,24 @@ go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE= go.uber.org/atomic v1.5.0/go.mod h1:sABNBOSYdrvTF6hTgEIbc7YasKWGhgEQZyfxyTvoXHQ= go.uber.org/atomic v1.6.0/go.mod h1:sABNBOSYdrvTF6hTgEIbc7YasKWGhgEQZyfxyTvoXHQ= go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= +go.uber.org/atomic v1.9.0 h1:ECmE8Bn/WFTYwEW/bpKD3M8VtR/zQVbavAoalC1PYyE= go.uber.org/atomic v1.9.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc= go.uber.org/automaxprocs v1.5.1/go.mod h1:BF4eumQw0P9GtnuxxovUd06vwm1o18oMzFtK66vU6XU= go.uber.org/goleak v1.1.10/go.mod h1:8a7PlsEVH3e/a/GLqe5IIrQx6GzcnRmZEufDUTk4A7A= +go.uber.org/goleak v1.1.11/go.mod h1:cwTWslyiVhfpKIDGSZEM2HlOvcqm+tG4zioyIeLoqMQ= go.uber.org/goleak v1.1.12/go.mod h1:cwTWslyiVhfpKIDGSZEM2HlOvcqm+tG4zioyIeLoqMQ= go.uber.org/multierr v1.1.0/go.mod h1:wR5kodmAFQ0UK8QlbwjlSNy0Z68gJhDJUG5sjR94q/0= go.uber.org/multierr v1.3.0/go.mod h1:VgVr7evmIr6uPjLBxg28wmKNXyqE9akIJ5XnfpiKl+4= go.uber.org/multierr v1.5.0/go.mod h1:FeouvMocqHpRaaGuG9EjoKcStLC43Zu/fmqdUMPcKYU= +go.uber.org/multierr v1.6.0 h1:y6IPFStTAIT5Ytl7/XYmHvzXQ7S3g/IeZW9hyZ5thw4= go.uber.org/multierr v1.6.0/go.mod h1:cdWPpRnG4AhwMwsgIHip0KRBQjJy5kYEpYjJxpXp9iU= go.uber.org/tools v0.0.0-20190618225709-2cfd321de3ee/go.mod h1:vJERXedbb3MVM5f9Ejo0C68/HhF8uaILCdgjnY+goOA= go.uber.org/zap v1.9.1/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q= go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q= go.uber.org/zap v1.13.0/go.mod h1:zwrFLgMcdUuIBviXEYEH1YKNaOBnKXsx2IPda5bBwHM= go.uber.org/zap v1.17.0/go.mod h1:MXVU+bhUf/A7Xi2HNOnopQOrmycQ5Ih87HtOu4q5SSo= +go.uber.org/zap v1.21.0 h1:WefMeulhovoZ2sYXz7st6K0sLj7bBhpiFaud4r4zST8= +go.uber.org/zap v1.21.0/go.mod h1:wjWOCqI0f2ZZrJF/UufIOkiC8ii6tm1iqIsLo76RfJw= golang.org/x/crypto v0.0.0-20171113213409-9f005a07e0d3/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20181009213950-7c1a557ab941/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= diff --git a/internal/log/log.go b/internal/log/log.go new file mode 100644 index 00000000..d01b94d4 --- /dev/null +++ b/internal/log/log.go @@ -0,0 +1,98 @@ +// Copyright 2022 Google LLC +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package log + +import ( + "io" + llog "log" + "os" + + "github.com/GoogleCloudPlatform/alloydb-auth-proxy/alloydb" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +// StdLogger is the standard logger that distinguishes between info and error +// logs. +type StdLogger struct { + infoLog *llog.Logger + errLog *llog.Logger +} + +// NewStdLogger create a Logger that uses out and err for informational and +// error messages. +func NewStdLogger(out, err io.Writer) alloydb.Logger { + return &StdLogger{ + infoLog: llog.New(out, "", llog.LstdFlags), + errLog: llog.New(err, "", llog.LstdFlags), + } +} + +func (l *StdLogger) Infof(format string, v ...interface{}) { + l.infoLog.Printf(format, v...) +} + +func (l *StdLogger) Errorf(format string, v ...interface{}) { + l.errLog.Printf(format, v...) +} + +func (l *StdLogger) Debugf(format string, v ...interface{}) { + l.infoLog.Printf(format, v...) +} + +// StructuredLogger writes log messages in JSON. +type StructuredLogger struct { + logger *zap.SugaredLogger +} + +func (l *StructuredLogger) Infof(format string, v ...interface{}) { + l.logger.Infof(format, v...) +} + +func (l *StructuredLogger) Errorf(format string, v ...interface{}) { + l.logger.Errorf(format, v...) +} + +func (l *StructuredLogger) Debugf(format string, v ...interface{}) { + l.logger.Infof(format, v...) +} + +// NewStructuredLogger creates a Logger that logs messages using JSON. +func NewStructuredLogger() (alloydb.Logger, func() error) { + // Configure structured logs to adhere to LogEntry format + // https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry + c := zap.NewProductionEncoderConfig() + c.LevelKey = "severity" + c.MessageKey = "message" + c.TimeKey = "timestamp" + c.EncodeLevel = zapcore.CapitalLevelEncoder + c.EncodeTime = zapcore.ISO8601TimeEncoder + + enc := zapcore.NewJSONEncoder(c) + core := zapcore.NewTee( + zapcore.NewCore(enc, zapcore.Lock(os.Stdout), zap.LevelEnablerFunc(func(l zapcore.Level) bool { + // Anything below error, goes to the info log. + return l < zapcore.ErrorLevel + })), + zapcore.NewCore(enc, zapcore.Lock(os.Stderr), zap.LevelEnablerFunc(func(l zapcore.Level) bool { + // Anything at error or higher goes to the error log. + return l >= zapcore.ErrorLevel + })), + ) + l := &StructuredLogger{ + logger: zap.New(core).Sugar(), + } + return l, l.logger.Sync +} diff --git a/internal/proxy/proxy.go b/internal/proxy/proxy.go index 0aa1a44a..690b727f 100644 --- a/internal/proxy/proxy.go +++ b/internal/proxy/proxy.go @@ -30,7 +30,6 @@ import ( "cloud.google.com/go/alloydbconn" "github.com/GoogleCloudPlatform/alloydb-auth-proxy/alloydb" "github.com/GoogleCloudPlatform/alloydb-auth-proxy/internal/gcloud" - "github.com/spf13/cobra" "golang.org/x/oauth2" ) @@ -90,33 +89,37 @@ type Config struct { // regardless of any open connections. WaitOnClose time.Duration - // Dialer specifies the dialer to use when connecting to AlloyDB - // instances. - Dialer alloydb.Dialer + // StructuredLogs sets all output to use JSON in the LogEntry format. + // See https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry + StructuredLogs bool } // DialerOptions builds appropriate list of options from the Config // values for use by alloydbconn.NewClient() -func (c *Config) DialerOptions() ([]alloydbconn.Option, error) { +func (c *Config) DialerOptions(l alloydb.Logger) ([]alloydbconn.Option, error) { opts := []alloydbconn.Option{ alloydbconn.WithUserAgent(c.UserAgent), } switch { case c.Token != "": + l.Infof("Authorizing with the -token flag") opts = append(opts, alloydbconn.WithTokenSource( oauth2.StaticTokenSource(&oauth2.Token{AccessToken: c.Token}), )) case c.CredentialsFile != "": + l.Infof("Authorizing with the credentials file at %q", c.CredentialsFile) opts = append(opts, alloydbconn.WithCredentialsFile( c.CredentialsFile, )) case c.GcloudAuth: + l.Infof("Authorizing with gcloud user credentials") ts, err := gcloud.TokenSource() if err != nil { return nil, err } opts = append(opts, alloydbconn.WithTokenSource(ts)) default: + l.Infof("Authorizing with Application Default Credentials") } return opts, nil @@ -172,7 +175,6 @@ type Client struct { // connCount. If not set, there is no limit. maxConns uint64 - cmd *cobra.Command dialer alloydb.Dialer // mnts is a list of all mounted sockets for this client @@ -181,16 +183,17 @@ type Client struct { // waitOnClose is the maximum duration to wait for open connections to close // when shutting down. waitOnClose time.Duration + + logger alloydb.Logger } // NewClient completes the initial setup required to get the proxy to a "steady" state. -func NewClient(ctx context.Context, cmd *cobra.Command, conf *Config) (*Client, error) { +func NewClient(ctx context.Context, d alloydb.Dialer, l alloydb.Logger, conf *Config) (*Client, error) { // Check if the caller has configured a dialer. // Otherwise, initialize a new one. - d := conf.Dialer if d == nil { var err error - dialerOpts, err := conf.DialerOptions() + dialerOpts, err := conf.DialerOptions(l) if err != nil { return nil, fmt.Errorf("error initializing dialer: %v", err) } @@ -208,19 +211,19 @@ func NewClient(ctx context.Context, cmd *cobra.Command, conf *Config) (*Client, for _, m := range mnts { mErr := m.Close() if mErr != nil { - cmd.PrintErrf("failed to close mount: %v", mErr) + l.Errorf("failed to close mount: %v", mErr) } } return nil, fmt.Errorf("[%v] Unable to mount socket: %v", inst.Name, err) } - cmd.Printf("[%s] Listening on %s\n", inst.Name, m.Addr()) + l.Infof("[%s] Listening on %s\n", inst.Name, m.Addr()) mnts = append(mnts, m) } c := &Client{ mnts: mnts, - cmd: cmd, + logger: l, dialer: d, maxConns: conf.MaxConnections, waitOnClose: conf.WaitOnClose, @@ -319,7 +322,7 @@ func (c *Client) serveSocketMount(ctx context.Context, s *socketMount) error { cConn, err := s.Accept() if err != nil { if nerr, ok := err.(net.Error); ok && nerr.Temporary() { - c.cmd.PrintErrf("[%s] Error accepting connection: %v\n", s.inst, err) + c.logger.Errorf("[%s] Error accepting connection: %v", s.inst, err) // For transient errors, wait a small amount of time to see if it resolves itself time.Sleep(10 * time.Millisecond) continue @@ -328,7 +331,7 @@ func (c *Client) serveSocketMount(ctx context.Context, s *socketMount) error { } // handle the connection in a separate goroutine go func() { - c.cmd.Printf("[%s] accepted connection from %s\n", s.inst, cConn.RemoteAddr()) + c.logger.Infof("[%s] accepted connection from %s\n", s.inst, cConn.RemoteAddr()) // A client has established a connection to the local socket. Before // we initiate a connection to the AlloyDB backend, increment the @@ -338,7 +341,7 @@ func (c *Client) serveSocketMount(ctx context.Context, s *socketMount) error { defer atomic.AddUint64(&c.connCount, ^uint64(0)) if c.maxConns > 0 && count > c.maxConns { - c.cmd.Printf("max connections (%v) exceeded, refusing new connection\n", c.maxConns) + c.logger.Infof("max connections (%v) exceeded, refusing new connection", c.maxConns) _ = cConn.Close() return } @@ -349,7 +352,7 @@ func (c *Client) serveSocketMount(ctx context.Context, s *socketMount) error { sConn, err := c.dialer.Dial(ctx, s.inst) if err != nil { - c.cmd.Printf("[%s] failed to connect to instance: %v\n", s.inst, err) + c.logger.Errorf("[%s] failed to connect to instance: %v\n", s.inst, err) cConn.Close() return } @@ -451,9 +454,9 @@ func (c *Client) proxyConn(inst string, client, server net.Conn) { client.Close() server.Close() if isErr { - c.cmd.PrintErrln(errDesc) + c.logger.Errorf(errDesc) } else { - c.cmd.Println(errDesc) + c.logger.Infof(errDesc) } }) } diff --git a/internal/proxy/proxy_test.go b/internal/proxy/proxy_test.go index f0555ca5..7f5ed3fc 100644 --- a/internal/proxy/proxy_test.go +++ b/internal/proxy/proxy_test.go @@ -27,8 +27,8 @@ import ( "time" "cloud.google.com/go/alloydbconn" + "github.com/GoogleCloudPlatform/alloydb-auth-proxy/internal/log" "github.com/GoogleCloudPlatform/alloydb-auth-proxy/internal/proxy" - "github.com/spf13/cobra" ) type testCase struct { @@ -210,8 +210,8 @@ func TestClientInitialization(t *testing.T) { for _, tc := range tcs { t.Run(tc.desc, func(t *testing.T) { - tc.in.Dialer = &fakeDialer{} - c, err := proxy.NewClient(ctx, &cobra.Command{}, tc.in) + logger := log.NewStdLogger(os.Stdout, os.Stdout) + c, err := proxy.NewClient(ctx, &fakeDialer{}, logger, tc.in) if err != nil { t.Fatalf("want error = nil, got = %v", err) } @@ -247,9 +247,9 @@ func TestClientLimitsMaxConnections(t *testing.T) { {Name: "proj:region:pg"}, }, MaxConnections: 1, - Dialer: d, } - c, err := proxy.NewClient(context.Background(), &cobra.Command{}, in) + logger := log.NewStdLogger(os.Stdout, os.Stdout) + c, err := proxy.NewClient(context.Background(), d, logger, in) if err != nil { t.Fatalf("proxy.NewClient error: %v", err) } @@ -313,15 +313,16 @@ func tryTCPDial(t *testing.T, addr string) net.Conn { } func TestClientCloseWaitsForActiveConnections(t *testing.T) { + logger := log.NewStdLogger(os.Stdout, os.Stdout) in := &proxy.Config{ Addr: "127.0.0.1", Port: 5000, Instances: []proxy.InstanceConnConfig{ {Name: "proj:region:pg"}, }, - Dialer: &fakeDialer{}, } - c, err := proxy.NewClient(context.Background(), &cobra.Command{}, in) + + c, err := proxy.NewClient(context.Background(), &fakeDialer{}, logger, in) if err != nil { t.Fatalf("proxy.NewClient error: %v", err) } @@ -336,7 +337,7 @@ func TestClientCloseWaitsForActiveConnections(t *testing.T) { in.WaitOnClose = time.Second in.Port = 5001 - c, err = proxy.NewClient(context.Background(), &cobra.Command{}, in) + c, err = proxy.NewClient(context.Background(), &fakeDialer{}, logger, in) if err != nil { t.Fatalf("proxy.NewClient error: %v", err) } @@ -365,9 +366,9 @@ func TestClientClosesCleanly(t *testing.T) { Instances: []proxy.InstanceConnConfig{ {Name: "proj:reg:inst"}, }, - Dialer: &fakeDialer{}, } - c, err := proxy.NewClient(context.Background(), &cobra.Command{}, in) + logger := log.NewStdLogger(os.Stdout, os.Stdout) + c, err := proxy.NewClient(context.Background(), &fakeDialer{}, logger, in) if err != nil { t.Fatalf("proxy.NewClient error want = nil, got = %v", err) } @@ -388,9 +389,9 @@ func TestClosesWithError(t *testing.T) { Instances: []proxy.InstanceConnConfig{ {Name: "proj:reg:inst"}, }, - Dialer: &errorDialer{}, } - c, err := proxy.NewClient(context.Background(), &cobra.Command{}, in) + logger := log.NewStdLogger(os.Stdout, os.Stdout) + c, err := proxy.NewClient(context.Background(), &errorDialer{}, logger, in) if err != nil { t.Fatalf("proxy.NewClient error want = nil, got = %v", err) } @@ -444,15 +445,15 @@ func TestClientInitializationWorksRepeatedly(t *testing.T) { Instances: []proxy.InstanceConnConfig{ {Name: "/projects/proj/locations/region/clusters/clust/instances/inst1"}, }, - Dialer: &fakeDialer{}, } - c, err := proxy.NewClient(ctx, &cobra.Command{}, in) + logger := log.NewStdLogger(os.Stdout, os.Stdout) + c, err := proxy.NewClient(ctx, &fakeDialer{}, logger, in) if err != nil { t.Fatalf("want error = nil, got = %v", err) } c.Close() - c, err = proxy.NewClient(ctx, &cobra.Command{}, in) + c, err = proxy.NewClient(ctx, &fakeDialer{}, logger, in) if err != nil { t.Fatalf("want error = nil, got = %v", err) }