summaryrefslogtreecommitdiffstats
path: root/core
diff options
context:
space:
mode:
Diffstat (limited to 'core')
-rw-r--r--core/connection.go27
-rw-r--r--core/request_handler.go79
-rw-r--r--core/trace.go70
-rw-r--r--core/trace_test.go265
4 files changed, 386 insertions, 55 deletions
diff --git a/core/connection.go b/core/connection.go
index f3ff964..ee5a06b 100644
--- a/core/connection.go
+++ b/core/connection.go
@@ -123,6 +123,8 @@ type Connection struct {
msgControlPing api.Message
msgControlPingReply api.Message
+
+ apiTrace *trace // API tracer (disabled by default)
}
func newConnection(binapi adapter.VppAPI, attempts int, interval time.Duration) *Connection {
@@ -145,6 +147,10 @@ func newConnection(binapi adapter.VppAPI, attempts int, interval time.Duration)
subscriptions: make(map[uint16][]*subscriptionCtx),
msgControlPing: msgControlPing,
msgControlPingReply: msgControlPingReply,
+ apiTrace: &trace{
+ list: make([]*api.Record, 0),
+ mux: &sync.Mutex{},
+ },
}
binapi.SetMsgCallback(c.msgCallback)
return c
@@ -480,3 +486,24 @@ func (c *Connection) sendConnEvent(event ConnectionEvent) {
log.Warn("Connection state channel is full, discarding value.")
}
}
+
+// Trace gives access to the API trace interface
+func (c *Connection) Trace() api.Trace {
+ return c.apiTrace
+}
+
+// trace records api message
+func (c *Connection) trace(msg api.Message, chId uint16, t time.Time, isReceived bool) {
+ if atomic.LoadInt32(&c.apiTrace.isEnabled) == 0 {
+ return
+ }
+ entry := &api.Record{
+ Message: msg,
+ Timestamp: t,
+ IsReceived: isReceived,
+ ChannelID: chId,
+ }
+ c.apiTrace.mux.Lock()
+ c.apiTrace.list = append(c.apiTrace.list, entry)
+ c.apiTrace.mux.Unlock()
+}
diff --git a/core/request_handler.go b/core/request_handler.go
index 95bd924..bf014de 100644
--- a/core/request_handler.go
+++ b/core/request_handler.go
@@ -17,6 +17,7 @@ package core
import (
"errors"
"fmt"
+ "reflect"
"sync/atomic"
"time"
@@ -54,51 +55,6 @@ func (c *Connection) watchRequests(ch *Channel) {
}
// processRequest processes a single request received on the request channel.
-func (c *Connection) sendMessage(context uint32, msg api.Message) error {
- // check whether we are connected to VPP
- if atomic.LoadUint32(&c.vppConnected) == 0 {
- return ErrNotConnected
- }
-
- /*log := log.WithFields(logger.Fields{
- "context": context,
- "msg_name": msg.GetMessageName(),
- "msg_crc": msg.GetCrcString(),
- })*/
-
- // retrieve message ID
- msgID, err := c.GetMessageID(msg)
- if err != nil {
- //log.WithError(err).Debugf("unable to retrieve message ID: %#v", msg)
- return err
- }
-
- //log = log.WithField("msg_id", msgID)
-
- // encode the message
- data, err := c.codec.EncodeMsg(msg, msgID)
- if err != nil {
- log.WithError(err).Debugf("unable to encode message: %#v", msg)
- return err
- }
-
- //log = log.WithField("msg_length", len(data))
-
- if log.Level >= logger.DebugLevel {
- log.Debugf("--> SEND: MSG %T %+v", msg, msg)
- }
-
- // send message to VPP
- err = c.vppClient.SendMsg(context, data)
- if err != nil {
- log.WithError(err).Debugf("unable to send message: %#v", msg)
- return err
- }
-
- return nil
-}
-
-// processRequest processes a single request received on the request channel.
func (c *Connection) processRequest(ch *Channel, req *vppRequest) error {
// check whether we are connected to VPP
if atomic.LoadUint32(&c.vppConnected) == 0 {
@@ -156,6 +112,7 @@ func (c *Connection) processRequest(ch *Channel, req *vppRequest) error {
}
// send the request to VPP
+ t := time.Now()
err = c.vppClient.SendMsg(context, data)
if err != nil {
log.WithFields(logger.Fields{
@@ -171,6 +128,7 @@ func (c *Connection) processRequest(ch *Channel, req *vppRequest) error {
}).Warnf("Unable to send message")
return err
}
+ c.trace(req.msg, ch.id, t, false)
if req.multi {
// send a control ping to determine end of the multipart response
@@ -188,6 +146,7 @@ func (c *Connection) processRequest(ch *Channel, req *vppRequest) error {
}).Debugf(" -> SEND MSG: %T", c.msgControlPing)
}
+ t = time.Now()
if err := c.vppClient.SendMsg(context, pingData); err != nil {
log.WithFields(logger.Fields{
"context": context,
@@ -195,6 +154,7 @@ func (c *Connection) processRequest(ch *Channel, req *vppRequest) error {
"error": err,
}).Warnf("unable to send control ping")
}
+ c.trace(c.msgControlPing, ch.id, t, false)
}
return nil
@@ -209,7 +169,7 @@ func (c *Connection) msgCallback(msgID uint16, data []byte) {
return
}
- msgType, name, crc, err := c.getMessageDataByID(msgID)
+ msg, err := c.getMessageByID(msgID)
if err != nil {
log.Warnln(err)
return
@@ -220,7 +180,7 @@ func (c *Connection) msgCallback(msgID uint16, data []byte) {
// - replies that don't have context as first field (comes as zero)
// - events that don't have context at all (comes as non zero)
//
- context, err := c.codec.DecodeMsgContext(data, msgType)
+ context, err := c.codec.DecodeMsgContext(data, msg.GetMessageType())
if err != nil {
log.WithField("msg_id", msgID).Warnf("Unable to decode message context: %v", err)
return
@@ -228,6 +188,14 @@ func (c *Connection) msgCallback(msgID uint16, data []byte) {
chanID, isMulti, seqNum := unpackRequestContext(context)
+ // decode and trace the message
+ msg = reflect.New(reflect.TypeOf(msg).Elem()).Interface().(api.Message)
+ if err = c.codec.DecodeMsg(data, msg); err != nil {
+ log.WithField("msg", msg).Warnf("Unable to decode message: %v", err)
+ return
+ }
+ c.trace(msg, chanID, time.Now(), true)
+
if log.Level == logger.DebugLevel { // for performance reasons - logrus does some processing even if debugs are disabled
log.WithFields(logger.Fields{
"context": context,
@@ -236,8 +204,8 @@ func (c *Connection) msgCallback(msgID uint16, data []byte) {
"channel": chanID,
"is_multi": isMulti,
"seq_num": seqNum,
- "msg_crc": crc,
- }).Debugf("<-- govpp RECEIVE: %s", name)
+ "msg_crc": msg.GetCrcString(),
+ }).Debugf("<-- govpp RECEIVE: %s", msg.GetMessageName())
}
if context == 0 || c.isNotificationMessage(msgID) {
@@ -411,12 +379,13 @@ func compareSeqNumbers(seqNum1, seqNum2 uint16) int {
return 1
}
-// Returns message data based on the message ID not depending on the message path
-func (c *Connection) getMessageDataByID(msgID uint16) (typ api.MessageType, name, crc string, err error) {
- for _, msgs := range c.msgMapByPath {
- if msg, ok := msgs[msgID]; ok {
- return msg.GetMessageType(), msg.GetMessageName(), msg.GetCrcString(), nil
+// Returns message based on the message ID not depending on message path
+func (c *Connection) getMessageByID(msgID uint16) (msg api.Message, err error) {
+ var ok bool
+ for _, messages := range c.msgMapByPath {
+ if msg, ok = messages[msgID]; ok {
+ return msg, nil
}
}
- return typ, name, crc, fmt.Errorf("unknown message received, ID: %d", msgID)
+ return nil, fmt.Errorf("unknown message received, ID: %d", msgID)
}
diff --git a/core/trace.go b/core/trace.go
new file mode 100644
index 0000000..ea9a57b
--- /dev/null
+++ b/core/trace.go
@@ -0,0 +1,70 @@
+// Copyright (c) 2021 Cisco and/or its affiliates.
+//
+// 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 core
+
+import (
+ "git.fd.io/govpp.git/api"
+ "sort"
+ "sync"
+ "sync/atomic"
+)
+
+// trace is the API tracer object synchronizing and keeping recoded messages.
+type trace struct {
+ list []*api.Record
+ mux *sync.Mutex
+
+ isEnabled int32
+}
+
+func (c *trace) Enable(enable bool) {
+ if enable && atomic.CompareAndSwapInt32(&c.isEnabled, 0, 1) {
+ log.Debugf("API trace enabled")
+ } else if atomic.CompareAndSwapInt32(&c.isEnabled, 1, 0) {
+ log.Debugf("API trace disabled")
+ }
+}
+
+func (c *trace) GetRecords() (list []*api.Record) {
+ c.mux.Lock()
+ for _, entry := range c.list {
+ list = append(list, entry)
+ }
+ c.mux.Unlock()
+ sort.Slice(list, func(i, j int) bool {
+ return list[i].Timestamp.Before(list[j].Timestamp)
+ })
+ return list
+}
+
+func (c *trace) GetRecordsForChannel(chId uint16) (list []*api.Record) {
+ c.mux.Lock()
+ for _, entry := range c.list {
+ if entry.ChannelID == chId {
+ list = append(list, entry)
+ }
+ }
+ c.mux.Unlock()
+ sort.Slice(list, func(i, j int) bool {
+ return list[i].Timestamp.Before(list[j].Timestamp)
+ })
+ return list
+}
+
+func (c *trace) Clear() {
+ c.mux.Lock()
+ c.list = make([]*api.Record, 0)
+ c.mux.Unlock()
+}
diff --git a/core/trace_test.go b/core/trace_test.go
new file mode 100644
index 0000000..1a29e7a
--- /dev/null
+++ b/core/trace_test.go
@@ -0,0 +1,265 @@
+package core_test
+
+import (
+ "git.fd.io/govpp.git/api"
+ interfaces "git.fd.io/govpp.git/binapi/interface"
+ "git.fd.io/govpp.git/binapi/ip"
+ "git.fd.io/govpp.git/binapi/l2"
+ "git.fd.io/govpp.git/binapi/memif"
+ "git.fd.io/govpp.git/binapi/vpe"
+ "git.fd.io/govpp.git/core"
+ . "github.com/onsi/gomega"
+ "strings"
+ "testing"
+)
+
+func TestTraceEnabled(t *testing.T) {
+ ctx := setupTest(t, false)
+ defer ctx.teardownTest()
+
+ Expect(ctx.conn.Trace()).ToNot(BeNil())
+ ctx.conn.Trace().Enable(true)
+
+ request := []api.Message{
+ &interfaces.CreateLoopback{},
+ &memif.MemifCreate{},
+ &l2.BridgeDomainAddDel{},
+ &ip.IPTableAddDel{},
+ }
+ reply := []api.Message{
+ &interfaces.CreateLoopbackReply{},
+ &memif.MemifCreateReply{},
+ &l2.BridgeDomainAddDelReply{},
+ &ip.IPTableAddDelReply{},
+ }
+
+ for i := 0; i < len(request); i++ {
+ ctx.mockVpp.MockReply(reply[i])
+ err := ctx.ch.SendRequest(request[i]).ReceiveReply(reply[i])
+ Expect(err).To(BeNil())
+ }
+
+ traced := ctx.conn.Trace().GetRecords()
+ Expect(traced).ToNot(BeNil())
+ Expect(traced).To(HaveLen(8))
+ for i, entry := range traced {
+ Expect(entry.Timestamp).ToNot(BeNil())
+ Expect(entry.Message.GetMessageName()).ToNot(Equal(""))
+ if strings.HasSuffix(entry.Message.GetMessageName(), "_reply") ||
+ strings.HasSuffix(entry.Message.GetMessageName(), "_details") {
+ Expect(entry.IsReceived).To(BeTrue())
+ } else {
+ Expect(entry.IsReceived).To(BeFalse())
+ }
+ if i%2 == 0 {
+ Expect(request[i/2].GetMessageName()).To(Equal(entry.Message.GetMessageName()))
+ } else {
+ Expect(reply[i/2].GetMessageName()).To(Equal(entry.Message.GetMessageName()))
+ }
+ }
+}
+
+func TestMultiRequestTraceEnabled(t *testing.T) {
+ ctx := setupTest(t, false)
+ defer ctx.teardownTest()
+
+ ctx.conn.Trace().Enable(true)
+
+ request := []api.Message{
+ &interfaces.SwInterfaceDump{},
+ }
+ reply := []api.Message{
+ &interfaces.SwInterfaceDetails{
+ SwIfIndex: 1,
+ },
+ &interfaces.SwInterfaceDetails{
+ SwIfIndex: 2,
+ },
+ &interfaces.SwInterfaceDetails{
+ SwIfIndex: 3,
+ },
+ &vpe.ControlPingReply{},
+ }
+
+ ctx.mockVpp.MockReply(reply...)
+ multiCtx := ctx.ch.SendMultiRequest(request[0])
+
+ i := 0
+ for {
+ last, err := multiCtx.ReceiveReply(reply[i])
+ Expect(err).ToNot(HaveOccurred())
+ if last {
+ break
+ }
+ i++
+ }
+
+ traced := ctx.conn.Trace().GetRecords()
+ Expect(traced).ToNot(BeNil())
+ Expect(traced).To(HaveLen(6))
+ for i, entry := range traced {
+ Expect(entry.Timestamp).ToNot(BeNil())
+ Expect(entry.Message.GetMessageName()).ToNot(Equal(""))
+ if strings.HasSuffix(entry.Message.GetMessageName(), "_reply") ||
+ strings.HasSuffix(entry.Message.GetMessageName(), "_details") {
+ Expect(entry.IsReceived).To(BeTrue())
+ } else {
+ Expect(entry.IsReceived).To(BeFalse())
+ }
+ if i == 0 {
+ Expect(request[0].GetMessageName()).To(Equal(entry.Message.GetMessageName()))
+ } else if i == len(traced)-1 {
+ msg := vpe.ControlPing{}
+ Expect(msg.GetMessageName()).To(Equal(entry.Message.GetMessageName()))
+ } else {
+ Expect(reply[i-1].GetMessageName()).To(Equal(entry.Message.GetMessageName()))
+ }
+ }
+}
+
+func TestTraceDisabled(t *testing.T) {
+ ctx := setupTest(t, false)
+ defer ctx.teardownTest()
+
+ ctx.conn.Trace().Enable(false)
+
+ request := []api.Message{
+ &interfaces.CreateLoopback{},
+ &memif.MemifCreate{},
+ &l2.BridgeDomainAddDel{},
+ &ip.IPTableAddDel{},
+ }
+ reply := []api.Message{
+ &interfaces.CreateLoopbackReply{},
+ &memif.MemifCreateReply{},
+ &l2.BridgeDomainAddDelReply{},
+ &ip.IPTableAddDelReply{},
+ }
+
+ for i := 0; i < len(request); i++ {
+ ctx.mockVpp.MockReply(reply[i])
+ err := ctx.ch.SendRequest(request[i]).ReceiveReply(reply[i])
+ Expect(err).To(BeNil())
+ }
+
+ traced := ctx.conn.Trace().GetRecords()
+ Expect(traced).To(BeNil())
+}
+
+func TestTracePerChannel(t *testing.T) {
+ ctx := setupTest(t, false)
+ defer ctx.teardownTest()
+
+ ctx.conn.Trace().Enable(true)
+
+ ch1 := ctx.ch
+ ch2, err := ctx.conn.NewAPIChannel()
+ Expect(err).ToNot(HaveOccurred())
+
+ requestCh1 := []api.Message{
+ &interfaces.CreateLoopback{},
+ &memif.MemifCreate{},
+ &l2.BridgeDomainAddDel{},
+ }
+ replyCh1 := []api.Message{
+ &interfaces.CreateLoopbackReply{},
+ &memif.MemifCreateReply{},
+ &l2.BridgeDomainAddDelReply{},
+ }
+ requestCh2 := []api.Message{
+ &ip.IPTableAddDel{},
+ }
+ replyCh2 := []api.Message{
+ &ip.IPTableAddDelReply{},
+ }
+
+ for i := 0; i < len(requestCh1); i++ {
+ ctx.mockVpp.MockReply(replyCh1[i])
+ err := ch1.SendRequest(requestCh1[i]).ReceiveReply(replyCh1[i])
+ Expect(err).To(BeNil())
+ }
+ for i := 0; i < len(requestCh2); i++ {
+ ctx.mockVpp.MockReply(replyCh2[i])
+ err := ch2.SendRequest(requestCh2[i]).ReceiveReply(replyCh2[i])
+ Expect(err).To(BeNil())
+ }
+
+ trace := ctx.conn.Trace().GetRecords()
+ Expect(trace).ToNot(BeNil())
+ Expect(trace).To(HaveLen(8))
+
+ // per channel
+ channel1, ok := ch1.(*core.Channel)
+ Expect(ok).To(BeTrue())
+ channel2, ok := ch2.(*core.Channel)
+ Expect(ok).To(BeTrue())
+
+ tracedCh1 := ctx.conn.Trace().GetRecordsForChannel(channel1.GetID())
+ Expect(tracedCh1).ToNot(BeNil())
+ Expect(tracedCh1).To(HaveLen(6))
+ for i, entry := range tracedCh1 {
+ Expect(entry.Timestamp).ToNot(BeNil())
+ Expect(entry.Message.GetMessageName()).ToNot(Equal(""))
+ if strings.HasSuffix(entry.Message.GetMessageName(), "_reply") ||
+ strings.HasSuffix(entry.Message.GetMessageName(), "_details") {
+ Expect(entry.IsReceived).To(BeTrue())
+ } else {
+ Expect(entry.IsReceived).To(BeFalse())
+ }
+ if i%2 == 0 {
+ Expect(requestCh1[i/2].GetMessageName()).To(Equal(entry.Message.GetMessageName()))
+ } else {
+ Expect(replyCh1[i/2].GetMessageName()).To(Equal(entry.Message.GetMessageName()))
+ }
+ }
+
+ tracedCh2 := ctx.conn.Trace().GetRecordsForChannel(channel2.GetID())
+ Expect(tracedCh2).ToNot(BeNil())
+ Expect(tracedCh2).To(HaveLen(2))
+ for i, entry := range tracedCh2 {
+ Expect(entry.Timestamp).ToNot(BeNil())
+ Expect(entry.Message.GetMessageName()).ToNot(Equal(""))
+ if strings.HasSuffix(entry.Message.GetMessageName(), "_reply") ||
+ strings.HasSuffix(entry.Message.GetMessageName(), "_details") {
+ Expect(entry.IsReceived).To(BeTrue())
+ } else {
+ Expect(entry.IsReceived).To(BeFalse())
+ }
+ if i%2 == 0 {
+ Expect(requestCh2[i/2].GetMessageName()).To(Equal(entry.Message.GetMessageName()))
+ } else {
+ Expect(replyCh2[i/2].GetMessageName()).To(Equal(entry.Message.GetMessageName()))
+ }
+ }
+}
+
+func TestTraceClear(t *testing.T) {
+ ctx := setupTest(t, false)
+ defer ctx.teardownTest()
+
+ ctx.conn.Trace().Enable(true)
+
+ request := []api.Message{
+ &interfaces.CreateLoopback{},
+ &memif.MemifCreate{},
+ }
+ reply := []api.Message{
+ &interfaces.CreateLoopbackReply{},
+ &memif.MemifCreateReply{},
+ }
+
+ for i := 0; i < len(request); i++ {
+ ctx.mockVpp.MockReply(reply[i])
+ err := ctx.ch.SendRequest(request[i]).ReceiveReply(reply[i])
+ Expect(err).To(BeNil())
+ }
+
+ traced := ctx.conn.Trace().GetRecords()
+ Expect(traced).ToNot(BeNil())
+ Expect(traced).To(HaveLen(4))
+
+ ctx.conn.Trace().Clear()
+ traced = ctx.conn.Trace().GetRecords()
+ Expect(traced).To(BeNil())
+ Expect(traced).To(BeEmpty())
+}