Merge pull request #255 from pact-foundation/fix/request-filters-in-v…

…erifier

Fix/request filters in verifier

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
 }

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

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,14 +42,15 @@ 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)
 		})
 	}
 
 	// 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 {

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")

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

internal/native/mock_server_test.go

@@ -13,7 +13,7 @@ import (
 )
 
 func init() {
-	Init()
+	Init("")
 }
 
 func TestMockServer_CreateAndCleanupMockServer(t *testing.T) {

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 |

internal/native/verifier_test.go

@@ -8,7 +8,7 @@ import (
 )
 
 func init() {
-	Init()
+	Init("INFO")
 }
 
 func TestVerifier_Version(t *testing.T) {

log/log.go

@@ -19,36 +19,39 @@ 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")
 	}
 }
 
 // TODO: use the unified logging method to the FFI
 
 // 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
@@ -59,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!
+`

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"
 )
 
@@ -148,7 +149,7 @@ func NewAsynchronousPact(config Config) (*AsynchronousPact, error) {
 		return nil, err
 	}
 
-	native.Init()
+	native.Init(string(logging.LogLevel()))
 
 	return provider, err
 }

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"
 )
 
@@ -222,7 +223,7 @@ func NewAsynchronousPact(config Config) (*AsynchronousPact, error) {
 		return nil, err
 	}
 
-	native.Init()
+	native.Init(string(logging.LogLevel()))
 
 	return provider, err
 }

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"
 )
 
@@ -279,7 +280,7 @@ func NewSynchronousPact(config Config) (*SynchronousPact, error) {
 		return nil, err
 	}
 
-	native.Init()
+	native.Init(string(logging.LogLevel()))
 
 	return provider, err
 }

provider/verifier.go

@@ -14,12 +14,15 @@ 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"
 	"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
@@ -34,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),
@@ -87,11 +90,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 +133,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 +152,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))