feat: api-trace

Signed-off-by: Vladimir Lavor <vlavor@cisco.com>
Change-Id: I7de363dfb3930db13a30e97f154c57d75c07f01c

8 files changed, 798 insertions, 55 deletions

diff --git a/.gitignore b/.gitignore
index 8e61e14..1e2f728 100644
--- a/.gitignore
+++ b/.gitignore
@@ -12,6 +12,7 @@ cmd/binapi-generator/binapi-generator
 cmd/vpp-proxy/vpp-proxy
 
 # examples
+examples/api-trace/api-trace
 examples/multi-vpp/multi-vpp
 examples/perf-bench/perf-bench
 examples/rpc-service/rpc-service
diff --git a/api/trace.go b/api/trace.go
new file mode 100644
index 0000000..4ff46e8
--- /dev/null
+++ b/api/trace.go
@@ -0,0 +1,46 @@
+//  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 api
+
+import (
+	"time"
+)
+
+// Trace gives access to the API trace tool, capturing outcoming and incoming messages
+// to and from GoVPP.
+type Trace interface {
+	// Enable allows to enable or disable API trace for a connection.
+	Enable(enable bool)
+
+	// GetRecords retrieves all messages collected (from all channels if they are used)
+	// since the point the trace was enabled or cleared.
+	GetRecords() []*Record
+
+	// GetRecordsForChannel retrieves messages collected by the given channel since
+	// the point the trace was enabled or cleared.
+	GetRecordsForChannel(chId uint16) []*Record
+
+	// Clear erases messages captured so far.
+	Clear()
+}
+
+// Record contains essential information about traced message, its timestamp and whether
+// the message was received or sent
+type Record struct {
+	Message    Message
+	Timestamp  time.Time
+	IsReceived bool
+	ChannelID  uint16
+}
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())
+}
diff --git a/examples/api-trace/README.md b/examples/api-trace/README.md
new file mode 100644
index 0000000..6cb6ce8
--- /dev/null
+++ b/examples/api-trace/README.md
@@ -0,0 +1,17 @@
+# API trace example
+
+The example demonstrates how to use GoVPP API trace functionality. Connection object `core.Connection` contains
+API tracer able to record API messages sent to and from VPP.
+
+Access to the tracer is done via `Trace()`. It allows accessing several methods to manage collected entries:
+* `Enable(<bool>)` either enables or disables the trace. Note that the trace is disabled by default and messages are not recorded while so.
+* `GetRecords() []*api.Record` provide messages collected since the plugin was enabled or cleared.
+* `GetRecordsForChannel(<channelID>) []*api.Record` provide messages collected on the given channel since the plugin was enabled or cleared.
+* `Clear()` removes recorded messages.
+
+A record is represented by `Record` type. It contains information about the message, its direction, time and channel ID. Following fields are available:
+* `Message api.Message` returns recorded entry as GoVPP Message.
+* `Timestamp time.Time` is the message timestamp.
+* `IsReceived bool` is true if the message is a reply or details message, false otherwise.
+* `ChannelID uint16` is the ID of channel processing the traced message. 
+
diff --git a/examples/api-trace/api-trace.go b/examples/api-trace/api-trace.go
new file mode 100644
index 0000000..3a78c7b
--- /dev/null
+++ b/examples/api-trace/api-trace.go
@@ -0,0 +1,348 @@
+// 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.
+
+// api-trace is and example how to use the GoVPP API trace tool.
+
+package main
+
+import (
+	"context"
+	"flag"
+	"fmt"
+	"git.fd.io/govpp.git"
+	"git.fd.io/govpp.git/adapter/socketclient"
+	"git.fd.io/govpp.git/api"
+	interfaces "git.fd.io/govpp.git/binapi/interface"
+	"git.fd.io/govpp.git/binapi/interface_types"
+	"git.fd.io/govpp.git/binapi/ip_types"
+	"git.fd.io/govpp.git/binapi/vpe"
+	"git.fd.io/govpp.git/core"
+	"log"
+)
+
+var (
+	sockAddr = flag.String("socket", socketclient.DefaultSocketName, "Path to VPP API socket file")
+)
+
+func main() {
+	flag.Parse()
+
+	fmt.Printf("Starting api-trace tool example\n\n")
+
+	// make synchronous VPP connection
+	conn, err := govpp.Connect(*sockAddr)
+	if err != nil {
+		log.Fatalln("ERROR:", err)
+	}
+	defer conn.Disconnect()
+
+	singleChannel(conn)
+	multiChannel(conn)
+	stream(conn)
+
+	fmt.Printf("Api-trace tool example finished\n\n")
+}
+
+func singleChannel(conn *core.Connection) {
+	// create new channel and perform simple compatibility check
+	ch, err := conn.NewAPIChannel()
+	if err != nil {
+		log.Fatalln("ERROR: creating channel failed:", err)
+	}
+	defer ch.Close()
+
+	fmt.Printf("=> Example 1\n\nEnabling API trace...\n")
+	conn.Trace().Enable(true)
+
+	if err := ch.CheckCompatiblity(append(vpe.AllMessages(), interfaces.AllMessages()...)...); err != nil {
+		log.Fatal(err)
+	}
+
+	// do some API calls
+	fmt.Printf("Calling VPP API...\n")
+	retrieveVersion(ch)
+	idx := createLoopback(ch)
+	addIPAddress("10.10.0.1/24", ch, idx)
+	interfaceDump(ch)
+	deleteLoopback(ch, idx)
+	fmt.Println()
+
+	fmt.Printf("API trace (api calls: %d):\n", len(conn.Trace().GetRecords()))
+	fmt.Printf("--------------------\n")
+	for _, item := range conn.Trace().GetRecords() {
+		printTrace(item)
+	}
+	fmt.Printf("--------------------\n")
+
+	fmt.Printf("Clearing API trace...\n\n")
+	conn.Trace().Clear()
+}
+
+func multiChannel(conn *core.Connection) {
+	ch1, err := conn.NewAPIChannel()
+	if err != nil {
+		log.Fatalln("ERROR: creating channel failed:", err)
+	}
+	defer ch1.Close()
+	ch2, err := conn.NewAPIChannel()
+	if err != nil {
+		log.Fatalln("ERROR: creating channel failed:", err)
+	}
+	defer ch2.Close()
+
+	//do API calls again
+	fmt.Printf("=> Example 2\n\nCalling VPP API (multi-channel)...\n")
+	retrieveVersion(ch1)
+	idx1 := createLoopback(ch1)
+	idx2 := createLoopback(ch2)
+	addIPAddress("20.10.0.1/24", ch1, idx1)
+	addIPAddress("30.10.0.1/24", ch2, idx2)
+	interfaceDump(ch1)
+	deleteLoopback(ch2, idx1)
+	deleteLoopback(ch1, idx2)
+	fmt.Println()
+
+	chan1, ok := ch1.(*core.Channel)
+	if !ok {
+		log.Fatalln("ERROR: incorrect type of channel 1:", err)
+	}
+	chan2, ok := ch2.(*core.Channel)
+	if !ok {
+		log.Fatalln("ERROR: incorrect type of channel 2:", err)
+	}
+
+	fmt.Printf("API trace for channel 1 (api calls: %d):\n", len(conn.Trace().GetRecordsForChannel(chan1.GetID())))
+	fmt.Printf("--------------------\n")
+	for _, item := range conn.Trace().GetRecordsForChannel(chan1.GetID()) {
+		printTrace(item)
+	}
+	fmt.Printf("--------------------\n")
+	fmt.Printf("API trace for channel 2 (api calls: %d):\n", len(conn.Trace().GetRecordsForChannel(chan2.GetID())))
+	fmt.Printf("--------------------\n")
+	for _, item := range conn.Trace().GetRecordsForChannel(chan2.GetID()) {
+		printTrace(item)
+	}
+	fmt.Printf("--------------------\n")
+	fmt.Printf("cumulative API trace (api calls: %d):\n", len(conn.Trace().GetRecords()))
+	fmt.Printf("--------------------\n")
+	for _, item := range conn.Trace().GetRecords() {
+		printTrace(item)
+	}
+	fmt.Printf("--------------------\n")
+
+	fmt.Printf("Clearing API trace...\n\n")
+	conn.Trace().Clear()
+}
+
+func stream(conn *core.Connection) {
+	// create new channel and perform simple compatibility check
+	s, err := conn.NewStream(context.Background())
+	if err != nil {
+		log.Fatalln("ERROR: creating channel failed:", err)
+	}
+	defer func() {
+		if err := s.Close(); err != nil {
+			log.Fatalf("failed to close stream: %v", err)
+		}
+	}()
+
+	// do some API calls
+	fmt.Printf("=> Example 3\n\nCalling VPP API (stream)...\n")
+	invokeRetrieveVersion(conn)
+	idx := invokeCreateLoopback(conn)
+	invokeAddIPAddress("40.10.0.1/24", conn, idx)
+	invokeInterfaceDump(conn)
+	invokeDeleteLoopback(conn, idx)
+	fmt.Println()
+
+	fmt.Printf("stream API trace (api calls: %d):\n", len(conn.Trace().GetRecords()))
+	fmt.Printf("--------------------\n")
+	for _, item := range conn.Trace().GetRecords() {
+		printTrace(item)
+	}
+	fmt.Printf("--------------------\n")
+
+	fmt.Printf("Clearing API trace...\n\n")
+	conn.Trace().GetRecords()
+}
+
+func retrieveVersion(ch api.Channel) {
+	req := &vpe.ShowVersion{}
+	reply := &vpe.ShowVersionReply{}
+
+	if err := ch.SendRequest(req).ReceiveReply(reply); err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return
+	}
+	fmt.Printf(" - retrieved VPP version: %s\n", reply.Version)
+}
+
+func invokeRetrieveVersion(c api.Connection) {
+	req := &vpe.ShowVersion{}
+	reply := &vpe.ShowVersionReply{}
+
+	if err := c.Invoke(context.Background(), req, reply); err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+	}
+	fmt.Printf(" - retrieved VPP version: %s\n", reply.Version)
+}
+
+func createLoopback(ch api.Channel) interface_types.InterfaceIndex {
+	req := &interfaces.CreateLoopback{}
+	reply := &interfaces.CreateLoopbackReply{}
+
+	if err := ch.SendRequest(req).ReceiveReply(reply); err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return 0
+	}
+	fmt.Printf(" - created loopback with index: %d\n", reply.SwIfIndex)
+	return reply.SwIfIndex
+}
+
+func invokeCreateLoopback(c api.Connection) interface_types.InterfaceIndex {
+	req := &interfaces.CreateLoopback{}
+	reply := &interfaces.CreateLoopbackReply{}
+
+	if err := c.Invoke(context.Background(), req, reply); err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return 0
+	}
+	fmt.Printf(" - created loopback with index: %d\n", reply.SwIfIndex)
+	return reply.SwIfIndex
+}
+
+func deleteLoopback(ch api.Channel, index interface_types.InterfaceIndex) {
+	req := &interfaces.DeleteLoopback{
+		SwIfIndex: index,
+	}
+	reply := &interfaces.DeleteLoopbackReply{}
+
+	if err := ch.SendRequest(req).ReceiveReply(reply); err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return
+	}
+	fmt.Printf(" - deleted loopback with index: %d\n", index)
+}
+
+func invokeDeleteLoopback(c api.Connection, index interface_types.InterfaceIndex) {
+	req := &interfaces.DeleteLoopback{
+		SwIfIndex: index,
+	}
+	reply := &interfaces.DeleteLoopbackReply{}
+
+	if err := c.Invoke(context.Background(), req, reply); err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return
+	}
+	fmt.Printf(" - deleted loopback with index: %d\n", index)
+}
+
+func addIPAddress(addr string, ch api.Channel, index interface_types.InterfaceIndex) {
+	ipAddr, err := ip_types.ParsePrefix(addr)
+	if err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return
+	}
+
+	req := &interfaces.SwInterfaceAddDelAddress{
+		SwIfIndex: index,
+		IsAdd:     true,
+		Prefix:    ip_types.AddressWithPrefix(ipAddr),
+	}
+	reply := &interfaces.SwInterfaceAddDelAddressReply{}
+
+	if err := ch.SendRequest(req).ReceiveReply(reply); err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return
+	}
+	fmt.Printf(" - IP address %s added to interface with index %d\n", addr, index)
+}
+
+func invokeAddIPAddress(addr string, c api.Connection, index interface_types.InterfaceIndex) {
+	ipAddr, err := ip_types.ParsePrefix(addr)
+	if err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return
+	}
+
+	req := &interfaces.SwInterfaceAddDelAddress{
+		SwIfIndex: index,
+		IsAdd:     true,
+		Prefix:    ip_types.AddressWithPrefix(ipAddr),
+	}
+	reply := &interfaces.SwInterfaceAddDelAddressReply{}
+
+	if err := c.Invoke(context.Background(), req, reply); err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return
+	}
+	fmt.Printf(" - IP address %s added to interface with index %d\n", addr, index)
+}
+
+func interfaceDump(ch api.Channel) {
+	reqCtx := ch.SendMultiRequest(&interfaces.SwInterfaceDump{
+		SwIfIndex: ^interface_types.InterfaceIndex(0),
+	})
+	for {
+		msg := &interfaces.SwInterfaceDetails{}
+		stop, err := reqCtx.ReceiveReply(msg)
+		if stop {
+			break
+		}
+		if err != nil {
+			fmt.Printf("ERROR: %v\n", err)
+			return
+		}
+		fmt.Printf(" - retrieved interface: %v (idx: %d)\n", msg.InterfaceName, msg.SwIfIndex)
+	}
+}
+
+func invokeInterfaceDump(c api.Connection) {
+	s, err := c.NewStream(context.Background())
+	if err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return
+	}
+	if err := s.SendMsg(&interfaces.SwInterfaceDump{}); err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return
+	}
+	if err := s.SendMsg(&vpe.ControlPing{}); err != nil {
+		fmt.Printf("ERROR: %v\n", err)
+		return
+	}
+	for {
+		reply, err := s.RecvMsg()
+		if err != nil {
+			fmt.Printf("ERROR: %v\n", err)
+			return
+		}
+		switch msg := reply.(type) {
+		case *interfaces.SwInterfaceDetails:
+			fmt.Printf(" - retrieved interface: %v (idx: %d)\n", msg.InterfaceName, msg.SwIfIndex)
+		case *vpe.ControlPingReply:
+			return
+		}
+	}
+}
+
+func printTrace(item *api.Record) {
+	h, m, s := item.Timestamp.Clock()
+	reply := ""
+	if item.IsReceived {
+		reply = "(reply)"
+	}
+	fmt.Printf("%dh:%dm:%ds:%dns %s %s\n", h, m, s,
+		item.Timestamp.Nanosecond(), item.Message.GetMessageName(), reply)
+}