diff --git a/go.mod b/go.mod index e03312a..5c42d9f 100644 --- a/go.mod +++ b/go.mod @@ -3,6 +3,7 @@ module github.com/int128/kauthproxy go 1.12 require ( + github.com/cenkalti/backoff v2.2.1+incompatible github.com/go-test/deep v1.0.4 github.com/golang/mock v1.3.1 github.com/google/wire v0.3.0 diff --git a/go.sum b/go.sum index 911b87b..41fc485 100644 --- a/go.sum +++ b/go.sum @@ -9,6 +9,8 @@ github.com/PuerkitoBio/urlesc v0.0.0-20160726150825-5bd2802263f2/go.mod h1:uGdko github.com/PuerkitoBio/urlesc v0.0.0-20170810143723-de5bf2ad4578 h1:d+Bc7a5rLufV/sSk/8dngufqelfh6jnri85riMAaF/M= github.com/PuerkitoBio/urlesc v0.0.0-20170810143723-de5bf2ad4578/go.mod h1:uGdkoq3SwY9Y+13GIhn11/XLaGBb4BfwItxLd5jeuXE= github.com/armon/consul-api v0.0.0-20180202201655-eb2c6b5be1b6/go.mod h1:grANhF5doyWs3UAsr3K4I6qtAmlQcZDesFNEHPZAzj8= +github.com/cenkalti/backoff v2.2.1+incompatible h1:tNowT99t7UNflLxfYYSlKYsBpXdEet03Pg2g16Swow4= +github.com/cenkalti/backoff v2.2.1+incompatible/go.mod h1:90ReRw6GdpyfrHakVjL/QHaoyV4aDUVVkXQJJJ3NXXM= github.com/coreos/etcd v3.3.10+incompatible/go.mod h1:uF7uidLiAD3TWHmW31ZFd/JWoc32PjwdhPthX9715RE= github.com/coreos/go-etcd v2.0.0+incompatible/go.mod h1:Jez6KQU2B/sWsbdaef3ED8NzMklzPG4d5KIOhIy30Tk= github.com/coreos/go-semver v0.2.0/go.mod h1:nnelYz7RCh+5ahJtPPxZlU+153eP4D4r3EedlOD2RNk= diff --git a/pkg/adaptors/logger/mock_logger/mock_logger.go b/pkg/adaptors/logger/mock_logger/mock_logger.go index ed748e3..7a1d25b 100644 --- a/pkg/adaptors/logger/mock_logger/mock_logger.go +++ b/pkg/adaptors/logger/mock_logger/mock_logger.go @@ -1,6 +1,8 @@ package mock_logger import ( + "time" + logger2 "github.com/int128/kauthproxy/pkg/adaptors/logger" "github.com/spf13/pflag" ) @@ -21,7 +23,7 @@ func (l *Logger) AddFlags(f *pflag.FlagSet) { } func (l *Logger) Printf(format string, args ...interface{}) { - l.t.Logf(format, args...) + logf(l.t, "", format, args) } func (l *Logger) V(level int) logger2.Verbose { @@ -33,6 +35,12 @@ type Verbose struct { } func (v *Verbose) Infof(format string, args ...interface{}) { - v.t.Logf("I] "+format, args...) - //log.Printf("I] "+format, args...) + logf(v.t, "I]", format, args) +} + +func logf(t testingLogf, level, format string, args []interface{}) { + t.Logf("%s %2s "+format, append([]interface{}{ + time.Now().Format("15:04:05.000"), + level, + }, args...)...) } diff --git a/pkg/usecases/authproxy/auth_proxy.go b/pkg/usecases/authproxy/auth_proxy.go index b1f16e3..3e6ecbc 100644 --- a/pkg/usecases/authproxy/auth_proxy.go +++ b/pkg/usecases/authproxy/auth_proxy.go @@ -5,6 +5,7 @@ import ( "net/url" "strings" + "github.com/cenkalti/backoff" "github.com/google/wire" "github.com/int128/kauthproxy/pkg/adaptors/logger" "github.com/int128/kauthproxy/pkg/adaptors/network" @@ -82,15 +83,20 @@ func (u *AuthProxy) Do(ctx context.Context, o Option) error { TargetHost: "localhost", TargetPort: transitPort, } - for { + b := backoff.NewExponentialBackOff() + if err := backoff.Retry(func() error { if err := u.run(ctx, pfo, rpo); err != nil { if xerrors.Is(err, portForwarderConnectionLostError) { - continue // retry connection + u.Logger.Printf("retrying: %s", err) + return err } - return xerrors.Errorf("error while running an authentication proxy: %w", err) + return backoff.Permanent(err) } return nil + }, b); err != nil { + return xerrors.Errorf("retry over: %w", err) } + return nil } // run runs a port forwarder and reverse proxy, and waits for them, as follows: @@ -122,6 +128,7 @@ func (u *AuthProxy) run(ctx context.Context, pfo portforwarder.Option, rpo rever } u.Logger.V(1).Infof("stopped the port forwarder") if ctx.Err() == nil { + u.Logger.V(1).Infof("connection of the port forwarder has lost") return portForwarderConnectionLostError } return nil diff --git a/pkg/usecases/authproxy/auth_proxy_test.go b/pkg/usecases/authproxy/auth_proxy_test.go index 135bad2..90a4edd 100644 --- a/pkg/usecases/authproxy/auth_proxy_test.go +++ b/pkg/usecases/authproxy/auth_proxy_test.go @@ -209,13 +209,15 @@ func TestAuthProxy_Do(t *testing.T) { }) t.Run("PortForwarderConnectionLost", func(t *testing.T) { + // 0ms: starting // 100ms: the port forwarder is ready // 200ms: the reverse proxy is ready // 400ms: lost connection - // 500ms: the port forwarder is ready - // 600ms: the reverse proxy is ready - // 700ms: cancel the context - ctx, cancel := context.WithTimeout(context.TODO(), 700*time.Millisecond) + // 900ms: retrying (after the backoff 500ms) + // 1000ms: the port forwarder is ready + // 1100ms: the reverse proxy is ready + // 1200ms: cancel the context + ctx, cancel := context.WithTimeout(context.TODO(), 1200*time.Millisecond) defer cancel() ctrl := gomock.NewController(t) defer ctrl.Finish()