From 6b42703889c84783c7c2f192a023c76236fbbf85 Mon Sep 17 00:00:00 2001 From: Matt Fellows Date: Fri, 9 Dec 2022 17:15:29 +1100 Subject: [PATCH 1/5] fix: HTTP requests weren't passing through HTTP proxy. Fixes #254 --- examples/provider_test.go | 11 +++++++++-- provider/verifier.go | 25 ++++++++++++++----------- 2 files changed, 23 insertions(+), 13 deletions(-) diff --git a/examples/provider_test.go b/examples/provider_test.go index de67fa1c9..909e5eb18 100644 --- a/examples/provider_test.go +++ b/examples/provider_test.go @@ -23,6 +23,9 @@ import ( var dir, _ = os.Getwd() var pactDir = fmt.Sprintf("%s/pacts", dir) +var requestFilterCalled = false +var stateHandlerCalled = false + func TestV3HTTPProvider(t *testing.T) { log.SetLogLevel("TRACE") version.CheckVersion() @@ -39,6 +42,7 @@ func TestV3HTTPProvider(t *testing.T) { f := func(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { l.Println("[DEBUG] HOOK request filter") + requestFilterCalled = true r.Header.Add("Authorization", "Bearer 1234-dynamic-value") next.ServeHTTP(w, r) }) @@ -46,7 +50,7 @@ func TestV3HTTPProvider(t *testing.T) { // Verify the Provider with local Pact Files err := verifier.VerifyProvider(t, provider.VerifyRequest{ - ProviderBaseURL: "http://localhost:8111", + ProviderBaseURL: "http://127.0.0.1:8111", Provider: "V3Provider", ProviderVersion: os.Getenv("APP_SHA"), BrokerURL: os.Getenv("PACT_BROKER_BASE_URL"), @@ -74,6 +78,7 @@ func TestV3HTTPProvider(t *testing.T) { }, StateHandlers: models.StateHandlers{ "User foo exists": func(setup bool, s models.ProviderState) (models.ProviderStateResponse, error) { + stateHandlerCalled = true if setup { l.Println("[DEBUG] HOOK calling user foo exists state handler", s) @@ -90,6 +95,8 @@ func TestV3HTTPProvider(t *testing.T) { }) assert.NoError(t, err) + assert.True(t, requestFilterCalled) + assert.True(t, stateHandlerCalled) } func TestV3MessageProvider(t *testing.T) { @@ -177,7 +184,7 @@ func startServer() { ) }) - l.Fatal(http.ListenAndServe("localhost:8111", mux)) + l.Fatal(http.ListenAndServe("127.0.0.1:8111", mux)) } type User struct { diff --git a/provider/verifier.go b/provider/verifier.go index eeca236a3..9f11af312 100644 --- a/provider/verifier.go +++ b/provider/verifier.go @@ -20,6 +20,8 @@ import ( "github.com/pact-foundation/pact-go/v2/utils" ) +const MESSAGE_PATH = "/__messages" + // Verifier is used to verify the provider side of an HTTP API contract type Verifier struct { // ClientTimeout specifies how long to wait for Pact CLI to start @@ -87,11 +89,6 @@ func (v *Verifier) verifyProviderRaw(request VerifyRequest, writer outputWriter) request.ProviderBaseURL = fmt.Sprintf("http://localhost:%d", port) } - err = request.validate(v.handle) - if err != nil { - return err - } - u, err = url.Parse(request.ProviderBaseURL) if err != nil { log.Panic("unable to parse the provider URL", err) @@ -135,16 +132,14 @@ func (v *Verifier) verifyProviderRaw(request VerifyRequest, writer outputWriter) // and error. The object will be marshalled to JSON for comparison. port, err := proxy.HTTPReverseProxy(opts) - // Modify any existing HTTP target to the proxy instead - // if t != nil { - // t.Port = uint16(getPort(u.Port())) - // } + if err != nil { + return err + } // Add any message targets - // TODO: properly parameterise these magic strings if len(request.MessageHandlers) > 0 { request.Transports = append(request.Transports, Transport{ - Path: "/__messages", + Path: MESSAGE_PATH, Protocol: "message", Port: uint16(port), }) @@ -156,6 +151,14 @@ func (v *Verifier) verifyProviderRaw(request VerifyRequest, writer outputWriter) request.ProviderStatesSetupURL = fmt.Sprintf("http://localhost:%d%s", port, providerStatesSetupPath) } + // Provider target should be the proxy + request.ProviderBaseURL = fmt.Sprintf("http://localhost:%d", port) + + err = request.validate(v.handle) + if err != nil { + return err + } + portErr := WaitForPort(port, "tcp", "localhost", v.ClientTimeout, fmt.Sprintf(`Timed out waiting for http verification proxy on port %d - check for errors`, port)) From f3f94ea9799e1e33374a2559937c3e00b00cbc80 Mon Sep 17 00:00:00 2001 From: Matt Fellows Date: Fri, 9 Dec 2022 17:29:41 +1100 Subject: [PATCH 2/5] fix: Rust logging can be set by SetLogLevel and environment variables --- consumer/http.go | 6 +---- internal/native/message_server_test.go | 1 - internal/native/mock_server.go | 34 +++++++++----------------- log/log.go | 33 +++++++++++++------------ message/v3/asynchronous_message.go | 2 +- message/v4/asynchronous_message.go | 2 +- message/v4/synchronous_message.go | 2 +- provider/verifier.go | 3 ++- 8 files changed, 36 insertions(+), 47 deletions(-) diff --git a/consumer/http.go b/consumer/http.go index 0eec6c55d..ee7c23d99 100644 --- a/consumer/http.go +++ b/consumer/http.go @@ -28,10 +28,6 @@ import ( "github.com/pact-foundation/pact-go/v2/utils" ) -func init() { - logging.InitLogging() -} - // MockHTTPProviderConfig provides the configuration options for an HTTP mock server // consumer test. type MockHTTPProviderConfig struct { @@ -124,7 +120,7 @@ func (p *httpMockProvider) configure() error { case models.V4: p.mockserver.WithSpecificationVersion(native.SPECIFICATION_VERSION_V4) } - native.Init() + native.Init(string(logging.LogLevel())) return nil } diff --git a/internal/native/message_server_test.go b/internal/native/message_server_test.go index fe2701ebc..19692e0d4 100644 --- a/internal/native/message_server_test.go +++ b/internal/native/message_server_test.go @@ -289,7 +289,6 @@ type jsonMessage struct { func TestGrpcPluginInteraction(t *testing.T) { tmpPactFolder, err := ioutil.TempDir("", "pact-go") assert.NoError(t, err) - log.InitLogging() log.SetLogLevel("TRACE") m := NewMessageServer("test-message-consumer", "test-message-provider") diff --git a/internal/native/mock_server.go b/internal/native/mock_server.go index a3abace45..3ebfbead7 100644 --- a/internal/native/mock_server.go +++ b/internal/native/mock_server.go @@ -170,7 +170,7 @@ import ( "fmt" "log" "os" - "sync" + "strings" "unsafe" ) @@ -210,11 +210,6 @@ const ( var logLevelStringToInt = map[string]logLevel{ "OFF": LOG_LEVEL_OFF, - "error": LOG_LEVEL_ERROR, - "warn": LOG_LEVEL_WARN, - "info": LOG_LEVEL_INFO, - "debug": LOG_LEVEL_DEBUG, - "trace": LOG_LEVEL_TRACE, "ERROR": LOG_LEVEL_ERROR, "WARN": LOG_LEVEL_WARN, "INFO": LOG_LEVEL_INFO, @@ -239,35 +234,30 @@ func Version() string { return C.GoString(v) } -var once = sync.Once{} +var loggingInitialised string // Init initialises the library -func Init() { +func Init(logLevel string) { log.Println("[DEBUG] initialising native interface") + logLevel = strings.ToUpper(logLevel) - once.Do(func() { - // Log to file if specified - pactLogLevel := os.Getenv("PACT_LOG_LEVEL") - logLevel := os.Getenv("LOG_LEVEL") - - level := "INFO" - if pactLogLevel != "" { - level = pactLogLevel - } else if logLevel != "" { - level = logLevel - } - - l, ok := logLevelStringToInt[level] + if loggingInitialised != "" { + log.Printf("log level ('%s') cannot be set to '%s' after initialisation\n", loggingInitialised, logLevel) + } else { + l, ok := logLevelStringToInt[logLevel] if !ok { l = LOG_LEVEL_INFO } + log.Printf("[DEBUG] initialised native log level to %s (%d)", logLevel, l) if os.Getenv("PACT_LOG_PATH") != "" { + log.Println("[DEBUG] initialised native log to log to file:", os.Getenv("PACT_LOG_PATH")) logToFile(os.Getenv("PACT_LOG_PATH"), l) } else { + log.Println("[DEBUG] initialised native log to log to stdout") logToStdout(l) } - }) + } } // MockServer is the public interface for managing the HTTP mock server diff --git a/log/log.go b/log/log.go index e8b08bbc5..2b60239d2 100644 --- a/log/log.go +++ b/log/log.go @@ -19,17 +19,25 @@ const ( logLevelError logutils.LogLevel = "ERROR" ) -func InitLogging() { +func init() { + pactLogLevel := os.Getenv("PACT_LOG_LEVEL") + logLevel := os.Getenv("LOG_LEVEL") + + level := defaultLogLevel + if pactLogLevel != "" { + level = pactLogLevel + } else if logLevel != "" { + level = logLevel + } + if logFilter == nil { logFilter = &logutils.LevelFilter{ Levels: []logutils.LogLevel{logLevelTrace, logLevelDebug, logLevelInfo, logLevelWarn, logLevelError}, - MinLevel: logutils.LogLevel(defaultLogLevel), + MinLevel: logutils.LogLevel(level), Writer: os.Stderr, } log.SetOutput(logFilter) log.Println("[DEBUG] initialised logging") - } else { - log.Println("[WARN] log level cannot be set after initialising, changing will have no effect") } } @@ -37,18 +45,13 @@ func InitLogging() { // SetLogLevel sets the default log level for the Pact framework func SetLogLevel(level logutils.LogLevel) error { - InitLogging() - - if logFilter == nil { - switch level { - case logLevelTrace, logLevelDebug, logLevelError, logLevelInfo, logLevelWarn: - logFilter.SetMinLevel(level) - return nil - default: - return fmt.Errorf(`invalid logLevel '%s'. Please specify one of "TRACE", "DEBUG", "INFO", "WARN", "ERROR"`, level) - } + switch level { + case logLevelTrace, logLevelDebug, logLevelError, logLevelInfo, logLevelWarn: + logFilter.SetMinLevel(level) + return nil + default: + return fmt.Errorf(`invalid logLevel '%s'. Please specify one of "TRACE", "DEBUG", "INFO", "WARN", "ERROR"`, level) } - return fmt.Errorf("log level ('%s') cannot be set to '%s' after initialisation", LogLevel(), level) } // LogLevel gets the current log level for the Pact framework diff --git a/message/v3/asynchronous_message.go b/message/v3/asynchronous_message.go index a94951194..ebee4406a 100644 --- a/message/v3/asynchronous_message.go +++ b/message/v3/asynchronous_message.go @@ -148,7 +148,7 @@ func NewAsynchronousPact(config Config) (*AsynchronousPact, error) { return nil, err } - native.Init() + native.Init(string(logging.LogLevel())) return provider, err } diff --git a/message/v4/asynchronous_message.go b/message/v4/asynchronous_message.go index 872ec52f1..a8f3c21e0 100644 --- a/message/v4/asynchronous_message.go +++ b/message/v4/asynchronous_message.go @@ -222,7 +222,7 @@ func NewAsynchronousPact(config Config) (*AsynchronousPact, error) { return nil, err } - native.Init() + native.Init(string(logging.LogLevel())) return provider, err } diff --git a/message/v4/synchronous_message.go b/message/v4/synchronous_message.go index 1ab5f49b9..a1c6aa9b1 100644 --- a/message/v4/synchronous_message.go +++ b/message/v4/synchronous_message.go @@ -279,7 +279,7 @@ func NewSynchronousPact(config Config) (*SynchronousPact, error) { return nil, err } - native.Init() + native.Init(string(logging.LogLevel())) return provider, err } diff --git a/provider/verifier.go b/provider/verifier.go index 9f11af312..d8515c884 100644 --- a/provider/verifier.go +++ b/provider/verifier.go @@ -14,6 +14,7 @@ import ( "github.com/pact-foundation/pact-go/v2/command" "github.com/pact-foundation/pact-go/v2/internal/native" + logging "github.com/pact-foundation/pact-go/v2/log" "github.com/pact-foundation/pact-go/v2/message" "github.com/pact-foundation/pact-go/v2/models" "github.com/pact-foundation/pact-go/v2/proxy" @@ -36,7 +37,7 @@ type Verifier struct { } func NewVerifier() *Verifier { - native.Init() + native.Init(string(logging.LogLevel())) return &Verifier{ handle: native.NewVerifier("pact-go", command.Version), From 4daa18cbc8111b1c7f513c81e489bccd99eadc81 Mon Sep 17 00:00:00 2001 From: Matt Fellows Date: Fri, 9 Dec 2022 22:58:10 +1100 Subject: [PATCH 3/5] chore: add PactCrash function to improve error reporting --- internal/native/mock_server_test.go | 2 +- internal/native/verifier.go | 2 -- internal/native/verifier_test.go | 2 +- log/log.go | 23 +++++++++++++++ provider/verify_request.go | 45 +++++++++++------------------ 5 files changed, 42 insertions(+), 32 deletions(-) diff --git a/internal/native/mock_server_test.go b/internal/native/mock_server_test.go index 5f02437fc..886a13e8f 100644 --- a/internal/native/mock_server_test.go +++ b/internal/native/mock_server_test.go @@ -13,7 +13,7 @@ import ( ) func init() { - Init() + Init("") } func TestMockServer_CreateAndCleanupMockServer(t *testing.T) { diff --git a/internal/native/verifier.go b/internal/native/verifier.go index 36fa9a3c8..22ca741f2 100644 --- a/internal/native/verifier.go +++ b/internal/native/verifier.go @@ -224,8 +224,6 @@ func (v *Verifier) SetPublishOptions(providerVersion string, buildUrl string, pr func (v *Verifier) Execute() error { // TODO: Validate - // TODO: Execute calls in sequence - result := C.pactffi_verifier_execute(v.handle) /// | Error | Description | diff --git a/internal/native/verifier_test.go b/internal/native/verifier_test.go index ff44e8b0a..665b839ac 100644 --- a/internal/native/verifier_test.go +++ b/internal/native/verifier_test.go @@ -8,7 +8,7 @@ import ( ) func init() { - Init() + Init("INFO") } func TestVerifier_Version(t *testing.T) { diff --git a/log/log.go b/log/log.go index 2b60239d2..4d1d2313d 100644 --- a/log/log.go +++ b/log/log.go @@ -62,3 +62,26 @@ func LogLevel() logutils.LogLevel { return logutils.LogLevel(defaultLogLevel) } + +func PactCrash(err error) { + log.Panicf(crashMessage, err.Error()) +} + +var crashMessage = `!!!!!!!!! PACT CRASHED !!!!!!!!! + +%s + +This is almost certainly a bug in Pact Go. It would be great if you could +open a bug report at: https://github.com/pact-foundation/pact-go/issues +so that we can fix it. + +There is additional debugging information above. If you open a bug report, +please rerun with SetLogLevel('trace') and include the +full output. + +SECURITY WARNING: Before including your log in the issue tracker, make sure you +have removed sensitive info such as login credentials and urls that you don't want +to share with the world. + +We're sorry about this! +` diff --git a/provider/verify_request.go b/provider/verify_request.go index 3e77fdb3a..2e749523a 100644 --- a/provider/verify_request.go +++ b/provider/verify_request.go @@ -13,6 +13,7 @@ import ( "time" "github.com/pact-foundation/pact-go/v2/internal/native" + logging "github.com/pact-foundation/pact-go/v2/log" "github.com/pact-foundation/pact-go/v2/message" "github.com/pact-foundation/pact-go/v2/models" "github.com/pact-foundation/pact-go/v2/proxy" @@ -162,13 +163,21 @@ type VerifyRequest struct { func (v *VerifyRequest) validate(handle *native.Verifier) error { if v.ProviderBaseURL == "" { - return fmt.Errorf("'ProviderBaseURL' must be provided") - } + logging.PactCrash(fmt.Errorf("ProviderBaseURL is a required field")) + } else { + url, err := url.Parse(v.ProviderBaseURL) + if err != nil { + return err + } - // TODO: review this - // We spin up our own transport for messages, but we need them defined for all others - if len(v.Transports) == 0 && len(v.MessageHandlers) == 0 && v.ProviderBaseURL == "" { - return fmt.Errorf("one of 'Transports' or 'ProviderBaseURL' must be provided") + port := getPort(v.ProviderBaseURL) + if port == -1 { + return fmt.Errorf("unknown scheme '%s' given to 'ProviderBaseURL', unable to determine default port. Use 'Transports' for non-HTTP providers instead", url.Scheme) + } + + handle.SetProviderInfo(v.Provider, url.Scheme, url.Hostname(), uint16(port), url.Path) + + log.Println("[DEBUG] v.Transports", v.Transports) } filterDescription := valueOrFromEnvironment(v.FilterDescription, "PACT_DESCRIPTION") @@ -222,7 +231,7 @@ func (v *VerifyRequest) validate(handle *native.Verifier) error { } } - if v.BrokerURL != "" && (v.ProviderVersion == "" || v.Provider == "") { + if valueOrFromEnvironment(v.BrokerURL, "PACT_BROKER_URL") != "" && (v.ProviderVersion == "" || v.Provider == "") { return errors.New("'ProviderVersion', and 'Provider' must be supplied if 'BrokerURL' given") } @@ -236,31 +245,11 @@ func (v *VerifyRequest) validate(handle *native.Verifier) error { } if v.BrokerURL != "" && v.Provider != "" { - handle.BrokerSourceWithSelectors(v.BrokerURL, valueOrFromEnvironment(v.BrokerUsername, "PACT_BROKER_USERNAME"), valueOrFromEnvironment(v.BrokerPassword, "PACT_BROKER_PASSWORD"), valueOrFromEnvironment(v.BrokerToken, "PACT_BROKER_TOKEN"), v.EnablePending, includeWIPPactsSince, v.ProviderTags, v.ProviderBranch, selectors, v.Tags) - } - - if v.ProviderBaseURL != "" { - url, err := url.Parse(v.ProviderBaseURL) - if err != nil { - return err - } - - port := getPort(v.ProviderBaseURL) - if port == -1 { - return fmt.Errorf("unknown scheme '%s' given to 'ProviderBaseURL', unable to determine default port. Use 'Transports' for non-HTTP providers instead", url.Scheme) - } - - // TODO: this actually needs to take the proxy address - handle.SetProviderInfo(v.Provider, url.Scheme, url.Hostname(), uint16(port), url.Path) - - log.Println("[DEBUG] v.Transports", v.Transports) - + handle.BrokerSourceWithSelectors(valueOrFromEnvironment(v.BrokerURL, "PACT_BROKER_URL"), valueOrFromEnvironment(v.BrokerUsername, "PACT_BROKER_USERNAME"), valueOrFromEnvironment(v.BrokerPassword, "PACT_BROKER_PASSWORD"), valueOrFromEnvironment(v.BrokerToken, "PACT_BROKER_TOKEN"), v.EnablePending, includeWIPPactsSince, v.ProviderTags, v.ProviderBranch, selectors, v.Tags) } handle.SetNoPactsIsError(v.FailIfNoPactsFound) - // normalise ProviderBaseURL to just another transport - return nil } From 4cd3727b9da93194e8848f340d599a519e002df1 Mon Sep 17 00:00:00 2001 From: Matt Fellows Date: Fri, 9 Dec 2022 23:19:24 +1100 Subject: [PATCH 4/5] chore: fix tests for logging --- message/v3/asynchronous_message.go | 1 + message/v4/asynchronous_message.go | 1 + message/v4/synchronous_message.go | 1 + provider/verify_request_test.go | 18 +++++++++++++----- 4 files changed, 16 insertions(+), 5 deletions(-) diff --git a/message/v3/asynchronous_message.go b/message/v3/asynchronous_message.go index ebee4406a..45d30bcc2 100644 --- a/message/v3/asynchronous_message.go +++ b/message/v3/asynchronous_message.go @@ -11,6 +11,7 @@ import ( "github.com/pact-foundation/pact-go/v2/internal/native" mockserver "github.com/pact-foundation/pact-go/v2/internal/native" + logging "github.com/pact-foundation/pact-go/v2/log" "github.com/pact-foundation/pact-go/v2/models" ) diff --git a/message/v4/asynchronous_message.go b/message/v4/asynchronous_message.go index a8f3c21e0..603cc7c16 100644 --- a/message/v4/asynchronous_message.go +++ b/message/v4/asynchronous_message.go @@ -11,6 +11,7 @@ import ( "github.com/pact-foundation/pact-go/v2/internal/native" mockserver "github.com/pact-foundation/pact-go/v2/internal/native" + logging "github.com/pact-foundation/pact-go/v2/log" "github.com/pact-foundation/pact-go/v2/models" ) diff --git a/message/v4/synchronous_message.go b/message/v4/synchronous_message.go index a1c6aa9b1..e9323b7fe 100644 --- a/message/v4/synchronous_message.go +++ b/message/v4/synchronous_message.go @@ -8,6 +8,7 @@ import ( "testing" "github.com/pact-foundation/pact-go/v2/internal/native" + logging "github.com/pact-foundation/pact-go/v2/log" "github.com/pact-foundation/pact-go/v2/models" ) diff --git a/provider/verify_request_test.go b/provider/verify_request_test.go index a5ffd03f7..0c13c5bbc 100644 --- a/provider/verify_request_test.go +++ b/provider/verify_request_test.go @@ -16,6 +16,7 @@ func TestVerifyRequestValidate(t *testing.T) { name string request *VerifyRequest err bool + panic bool }{ {name: "valid parameters", request: &VerifyRequest{ PactURLs: []string{"http://localhost:1234/path/to/pact"}, @@ -25,15 +26,21 @@ func TestVerifyRequestValidate(t *testing.T) { }, err: false}, {name: "no base URL provided", request: &VerifyRequest{ PactURLs: []string{"http://localhost:1234/path/to/pact"}, - }, err: true}, + }, err: true, panic: true}, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - err := tt.request.validate(handle) - if tt.err { - assert.Error(t, err) + if tt.panic { + assert.Panics(t, (func() { + tt.request.validate(handle) + })) } else { - assert.NoError(t, err) + err := tt.request.validate(handle) + if tt.err { + assert.Error(t, err) + } else { + assert.NoError(t, err) + } } }) } @@ -55,6 +62,7 @@ func TestVerifyRequestValidate(t *testing.T) { }, err: true}, {name: "broker url without name/version", request: &VerifyRequest{ BrokerURL: "http://localhost:1234", + ProviderBaseURL: "http://localhost:8080", ProviderVersion: "1.0.0", BrokerPassword: "1234", }, err: true}, From 46d3f1165edb91a81406dfec31d76b7f883e77f8 Mon Sep 17 00:00:00 2001 From: Matt Fellows Date: Fri, 9 Dec 2022 23:34:18 +1100 Subject: [PATCH 5/5] chore: fix matt test --- examples/plugin/consumer_plugin_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/examples/plugin/consumer_plugin_test.go b/examples/plugin/consumer_plugin_test.go index 957edb156..647156ca9 100644 --- a/examples/plugin/consumer_plugin_test.go +++ b/examples/plugin/consumer_plugin_test.go @@ -75,7 +75,7 @@ func TestTCPInteraction(t *testing.T) { ExecuteTest(t, func(transport message.TransportConfig, m message.SynchronousMessage) error { fmt.Println("matt TCP transport running on", transport) - str, err := callMattServiceTCP(transport, "hellotcp!") + str, err := callMattServiceTCP(transport, "hellotcp") assert.Equal(t, "tcpworld", str) return err