Lookup message name by ID when receiving unexpected message

Change-Id: I693e8084b7e3f036dec5e557dc772857bb7d5f3d
Signed-off-by: Ondrej Fabry <ofabry@cisco.com>

5 files changed, 71 insertions, 20 deletions

diff --git a/adapter/vppapiclient/vppapiclient_adapter.go b/adapter/vppapiclient/vppapiclient_adapter.go
index 10ec53b..e9948e8 100644
--- a/adapter/vppapiclient/vppapiclient_adapter.go
+++ b/adapter/vppapiclient/vppapiclient_adapter.go
@@ -124,7 +124,7 @@ func (a *vppAPIClientAdapter) Disconnect() {
 
 // GetMsgID returns a runtime message ID for the given message name and CRC.
 func (a *vppAPIClientAdapter) GetMsgID(msgName string, msgCrc string) (uint16, error) {
-	nameAndCrc := C.CString(fmt.Sprintf("%s_%s", msgName, msgCrc))
+	nameAndCrc := C.CString(msgName + "_" + msgCrc)
 	defer C.free(unsafe.Pointer(nameAndCrc))
 
 	msgID := uint16(C.govpp_get_msg_index(nameAndCrc))
diff --git a/api/api.go b/api/api.go
index 60508cd..eafdf22 100644
--- a/api/api.go
+++ b/api/api.go
@@ -78,6 +78,8 @@ type MessageDecoder interface {
 type MessageIdentifier interface {
 	// GetMessageID returns message identifier of given API message.
 	GetMessageID(msg Message) (uint16, error)
+	// LookupByID looks up message name and crc by ID
+	LookupByID(ID uint16) (string, error)
 }
 
 // Channel is the main communication interface with govpp core. It contains two Go channels, one for sending the requests
@@ -231,6 +233,7 @@ func (ch *Channel) receiveReplyInternal(msg Message) (LastReplyReceived bool, er
 				LastReplyReceived = true
 				return
 			}
+
 			// message checks
 			expMsgID, err := ch.MsgIdentifier.GetMessageID(msg)
 			if err != nil {
@@ -238,20 +241,31 @@ func (ch *Channel) receiveReplyInternal(msg Message) (LastReplyReceived bool, er
 					msg.GetMessageName(), msg.GetCrcString())
 				return false, err
 			}
+
 			if vppReply.MessageID != expMsgID {
+				var msgNameCrc string
+				if nameCrc, err := ch.MsgIdentifier.LookupByID(vppReply.MessageID); err != nil {
+					msgNameCrc = err.Error()
+				} else {
+					msgNameCrc = nameCrc
+				}
+
 				if ch.lastTimedOut {
-					logrus.Warnf("received invalid message ID, expected %d (%s), but got %d (probably timed out reply from previous request)",
-						expMsgID, msg.GetMessageName(), vppReply.MessageID)
+					logrus.Warnf("received invalid message ID, expected %d (%s), but got %d (%s) (probably timed out reply from previous request)",
+						expMsgID, msg.GetMessageName(), vppReply.MessageID, msgNameCrc)
 					continue
 				}
-				err = fmt.Errorf("received invalid message ID, expected %d (%s), but got %d (check if multiple goroutines are not sharing single GoVPP channel)",
-					expMsgID, msg.GetMessageName(), vppReply.MessageID)
+
+				err = fmt.Errorf("received invalid message ID, expected %d (%s), but got %d (%s) (check if multiple goroutines are not sharing single GoVPP channel)",
+					expMsgID, msg.GetMessageName(), vppReply.MessageID, msgNameCrc)
 				return false, err
 			}
+
 			ch.lastTimedOut = false
 			// decode the message
 			err = ch.MsgDecoder.DecodeMsg(vppReply.Data, msg)
 			return false, err
+
 		case <-timer.C:
 			ch.lastTimedOut = true
 			err = fmt.Errorf("no reply received within the timeout period %s", ch.replyTimeout)
diff --git a/api/api_test.go b/api/api_test.go
index 62541ab..a439986 100644
--- a/api/api_test.go
+++ b/api/api_test.go
@@ -321,7 +321,6 @@ func TestCheckMessageCompatibility(t *testing.T) {
 	err := ctx.ch.CheckMessageCompatibility(&interfaces.SwInterfaceSetFlags{})
 	Expect(err).ShouldNot(HaveOccurred())
 }
-
 func TestSetReplyTimeout(t *testing.T) {
 	ctx := setupTest(t)
 	defer ctx.teardownTest()
@@ -483,13 +482,15 @@ func TestReceiveReplyAfterTimeout(t *testing.T) {
 	Expect(err).ShouldNot(HaveOccurred())
 }
 
-/*
-	TODO: fix mock adapter
-	This test will fail because mock adapter will stop sending replies
-	when it encounters control_ping_reply from multi request,
-	thus never sending reply for next request
-
 func TestReceiveReplyAfterTimeoutMultiRequest(t *testing.T) {
+	/*
+		TODO: fix mock adapter
+		This test will fail because mock adapter will stop sending replies
+		when it encounters control_ping_reply from multi request,
+		thus never sending reply for next request
+	*/
+	t.Skip()
+
 	ctx := setupTest(t)
 	defer ctx.teardownTest()
 
@@ -544,4 +545,19 @@ func TestReceiveReplyAfterTimeoutMultiRequest(t *testing.T) {
 	err = ctx.ch.SendRequest(req).ReceiveReply(reply)
 	Expect(err).ShouldNot(HaveOccurred())
 }
-*/
+
+func TestInvalidMessageID(t *testing.T) {
+	ctx := setupTest(t)
+	defer ctx.teardownTest()
+
+	// first one request should work
+	ctx.mockVpp.MockReply(&vpe.ShowVersionReply{})
+	err := ctx.ch.SendRequest(&vpe.ShowVersion{}).ReceiveReply(&vpe.ShowVersionReply{})
+	Expect(err).ShouldNot(HaveOccurred())
+
+	// second should fail with error invalid message ID
+	ctx.mockVpp.MockReply(&vpe.ShowVersionReply{})
+	err = ctx.ch.SendRequest(&vpe.ControlPing{}).ReceiveReply(&vpe.ControlPingReply{})
+	Expect(err).Should(HaveOccurred())
+	Expect(err.Error()).To(ContainSubstring("invalid message ID"))
+}
diff --git a/core/core.go b/core/core.go
index b912715..ebe7f68 100644
--- a/core/core.go
+++ b/core/core.go
@@ -73,14 +73,14 @@ type Connection struct {
 	connected uint32             // non-zero if the adapter is connected to VPP
 	codec     *MsgCodec          // message codec
 
-	msgIDs     map[string]uint16 // map of message IDs indexed by message name + CRC
 	msgIDsLock sync.RWMutex      // lock for the message IDs map
+	msgIDs     map[string]uint16 // map of message IDs indexed by message name + CRC
 
-	channels     map[uint32]*api.Channel // map of all API channels indexed by the channel ID
 	channelsLock sync.RWMutex            // lock for the channels map
+	channels     map[uint32]*api.Channel // map of all API channels indexed by the channel ID
 
-	notifSubscriptions     map[uint16][]*api.NotifSubscription // map od all notification subscriptions indexed by message ID
 	notifSubscriptionsLock sync.RWMutex                        // lock for the subscriptions map
+	notifSubscriptions     map[uint16][]*api.NotifSubscription // map od all notification subscriptions indexed by message ID
 
 	maxChannelID uint32 // maximum used client ID
 	pingReqID    uint16 // ID if the ControlPing message
@@ -306,7 +306,7 @@ func (c *Connection) healthCheckLoop(connChan chan ConnectionEvent) {
 			failedChecks = 0
 		}
 
-		if failedChecks >= healthCheckThreshold {
+		if failedChecks > healthCheckThreshold {
 			// in case of error, break & disconnect
 			log.Errorf("VPP health check failed: %v", err)
 			// signal disconnected event via channel
diff --git a/core/request_handler.go b/core/request_handler.go
index 4a62754..7c185cd 100644
--- a/core/request_handler.go
+++ b/core/request_handler.go
@@ -24,6 +24,10 @@ import (
 	"git.fd.io/govpp.git/api"
 )
 
+var (
+	ErrNotConnected = errors.New("not connected to VPP, ignoring the request")
+)
+
 // watchRequests watches for requests on the request API channel and forwards them as messages to VPP.
 func (c *Connection) watchRequests(ch *api.Channel, chMeta *channelMetadata) {
 	for {
@@ -48,7 +52,7 @@ func (c *Connection) watchRequests(ch *api.Channel, chMeta *channelMetadata) {
 func (c *Connection) processRequest(ch *api.Channel, chMeta *channelMetadata, req *api.VppRequest) error {
 	// check whether we are connected to VPP
 	if atomic.LoadUint32(&c.connected) == 0 {
-		err := errors.New("not connected to VPP, ignoring the request")
+		err := ErrNotConnected
 		log.Error(err)
 		sendReply(ch, &api.VppReply{Error: err})
 		return err
@@ -189,9 +193,11 @@ func (c *Connection) GetMessageID(msg api.Message) (uint16, error) {
 
 // messageNameToID returns message ID of a message identified by its name and CRC.
 func (c *Connection) messageNameToID(msgName string, msgCrc string) (uint16, error) {
+	msgKey := msgName + "_" + msgCrc
+
 	// try to get the ID from the map
 	c.msgIDsLock.RLock()
-	id, ok := c.msgIDs[msgName+msgCrc]
+	id, ok := c.msgIDs[msgKey]
 	c.msgIDsLock.RUnlock()
 	if ok {
 		return id, nil
@@ -209,8 +215,23 @@ func (c *Connection) messageNameToID(msgName string, msgCrc string) (uint16, err
 	}
 
 	c.msgIDsLock.Lock()
-	c.msgIDs[msgName+msgCrc] = id
+	c.msgIDs[msgKey] = id
 	c.msgIDsLock.Unlock()
 
 	return id, nil
 }
+
+// LookupByID looks up message name and crc by ID.
+func (c *Connection) LookupByID(ID uint16) (string, error) {
+	if c == nil {
+		return "", errors.New("nil connection passed in")
+	}
+
+	for key, id := range c.msgIDs {
+		if id == ID {
+			return key, nil
+		}
+	}
+
+	return "", fmt.Errorf("unknown message ID: %d", ID)
+}