From 280b1c6c83b676ef4e592f4ecf60cb5b54b6a753 Mon Sep 17 00:00:00 2001
From: Ondrej Fabry <ofabry@cisco.com>
Date: Tue, 16 Jun 2020 10:40:34 +0200
Subject: Optimize socketclient adapter and add various code improvements

This commit includes:

Features
- optimized [socketclient](adapter/socketclient) adapter and add method to set client name
- added list of compatible messages to `CompatibilityError`

Fixes
- `MsgCodec` will recover panic occurring during a message decoding
- calling `Unsubscibe` will close the notification channel

Other
- improved log messages to provide more relevant info

Examples
- added more code samples of working with unions in [union example](examples/union-example)
- added profiling mode to [perf bench](examples/perf-bench) example
- improved [simple client](examples/simple-client) example to work properly even with multiple runs

Dependencies
- updated `github.com/sirupsen/logrus` dep to `v1.6.0`
- updated `github.com/lunixbochs/struc` dep to `v0.0.0-20200521075829-a4cb8d33dbbe`

Change-Id: I136a3968ccf9e93760d7ee2b9902fc7e6390a09d
Signed-off-by: Ondrej Fabry <ofabry@cisco.com>
---
 CHANGELOG.md                            |  23 ++
 Makefile                                |   2 +-
 adapter/socketclient/doc.go             |  13 +-
 adapter/socketclient/socketclient.go    | 437 ++++++++++++++++++--------------
 api/binapi.go                           |  33 ++-
 codec/msg_codec.go                      |  20 +-
 core/channel.go                         |  14 +-
 core/channel_test.go                    |   2 +-
 core/connection.go                      |  18 +-
 core/log.go                             |  21 +-
 core/request_handler.go                 |  20 +-
 examples/perf-bench/perf-bench.go       |  23 +-
 examples/simple-client/simple_client.go |  78 +++---
 examples/union-example/union_example.go | 101 ++++----
 go.mod                                  |   6 +-
 go.sum                                  |  19 +-
 version/version.go                      |  23 +-
 17 files changed, 521 insertions(+), 332 deletions(-)

diff --git a/CHANGELOG.md b/CHANGELOG.md
index 145d1b1..86e3edc 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -11,6 +11,29 @@ This file lists changes for the GoVPP releases.
 -
 -->
 
+## 0.4.0 (in development)
+> _NOT RELEASED YET_
+
+### Features
+- optimized [socketclient](adapter/socketclient) adapter and add method to set client name
+- added list of compatible messages to `CompatibilityError`
+
+### Fixes
+- `MsgCodec` will recover panic occurring during a message decoding  
+- calling `Unsubscibe` will close the notification channel 
+
+### Other
+- improved log messages to provide more relevant info
+
+#### Examples
+- added more code samples of working with unions in [union example](examples/union-example)
+- added profiling mode to [perf bench](examples/perf-bench) example
+- improved [simple client](examples/simple-client) example to work properly even with multiple runs
+
+#### Dependencies
+- updated `github.com/sirupsen/logrus` dep to `v1.6.0`
+- updated `github.com/lunixbochs/struc` dep to `v0.0.0-20200521075829-a4cb8d33dbbe`
+
 ## 0.3.5
 > _18 May 2020_
 
diff --git a/Makefile b/Makefile
index 4297746..e5bd0bd 100644
--- a/Makefile
+++ b/Makefile
@@ -101,7 +101,7 @@ gen-binapi-docker: install-generator ## Generate binapi code (using Docker)
 		-v "$(shell pwd):/govpp" -w /govpp \
 		-u "$(shell id -u):$(shell id -g)" \
 		"${VPP_IMG}" \
-	  sh -xc "cd $(BINAPI_DIR) && $(cmds)"
+	  sh -exc "cd $(BINAPI_DIR) && $(cmds)"
 
 extras:
 	@make -C extras
diff --git a/adapter/socketclient/doc.go b/adapter/socketclient/doc.go
index 0f93c56..cbb00a2 100644
--- a/adapter/socketclient/doc.go
+++ b/adapter/socketclient/doc.go
@@ -21,13 +21,18 @@
 //
 // Requirements
 //
-// The socketclient will connect to /run/vpp-api.sock by default. However this
-// is not enabled in VPP configuration by default.
+// The socketclient connects to unix domain socket defined in VPP configuration.
 //
-// To enable the socket in VPP, add following section to VPP config.
+// It is enabled by default at /run/vpp/api.sock by the following config section:
 //
 //	socksvr {
-//		default
+//		socket-name default
+//	}
+//
+// If you want to use custom socket path:
+//
+//	socksvr {
+//		socket-name /run/vpp/api.sock
 //	}
 //
 package socketclient
diff --git a/adapter/socketclient/socketclient.go b/adapter/socketclient/socketclient.go
index 366163f..1ee067f 100644
--- a/adapter/socketclient/socketclient.go
+++ b/adapter/socketclient/socketclient.go
@@ -16,7 +16,8 @@ package socketclient
 
 import (
 	"bufio"
-	"bytes"
+	"encoding/binary"
+	"errors"
 	"fmt"
 	"io"
 	"net"
@@ -27,8 +28,7 @@ import (
 	"time"
 
 	"github.com/fsnotify/fsnotify"
-	"github.com/lunixbochs/struc"
-	logger "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
 
 	"git.fd.io/govpp.git/adapter"
 	"git.fd.io/govpp.git/codec"
@@ -36,38 +36,34 @@ import (
 
 const (
 	// DefaultSocketName is default VPP API socket file path.
-	DefaultSocketName = adapter.DefaultBinapiSocket
-	legacySocketName  = "/run/vpp-api.sock"
+	DefaultSocketName = "/run/vpp/api.sock"
+	// DefaultClientName is used for identifying client in socket registration
+	DefaultClientName = "govppsock"
 )
 
 var (
+
 	// DefaultConnectTimeout is default timeout for connecting
 	DefaultConnectTimeout = time.Second * 3
 	// DefaultDisconnectTimeout is default timeout for discconnecting
 	DefaultDisconnectTimeout = time.Millisecond * 100
-	// MaxWaitReady defines maximum duration before waiting for socket file
-	// times out
+	// MaxWaitReady defines maximum duration of waiting for socket file
 	MaxWaitReady = time.Second * 10
-	// ClientName is used for identifying client in socket registration
-	ClientName = "govppsock"
 )
 
 var (
-	// Debug is global variable that determines debug mode
-	Debug = os.Getenv("DEBUG_GOVPP_SOCK") != ""
-	// DebugMsgIds is global variable that determines debug mode for msg ids
-	DebugMsgIds = os.Getenv("DEBUG_GOVPP_SOCKMSG") != ""
+	debug       = strings.Contains(os.Getenv("DEBUG_GOVPP"), "socketclient")
+	debugMsgIds = strings.Contains(os.Getenv("DEBUG_GOVPP"), "msgtable")
 
-	// Log is global logger
-	Log = logger.New()
+	logger = logrus.New()
+	log    = logger.WithField("logger", "govpp/socketclient")
 )
 
-// init initializes global logger, which logs debug level messages to stdout.
+// init initializes global logger
 func init() {
-	Log.Out = os.Stdout
-	if Debug {
-		Log.Level = logger.DebugLevel
-		Log.Debug("govpp/socketclient: enabled debug mode")
+	if debug {
+		logger.Level = logrus.DebugLevel
+		log.Debug("govpp: debug level enabled for socketclient")
 	}
 }
 
@@ -88,12 +84,13 @@ const socketMissing = `
 
 var warnOnce sync.Once
 
-func (c *vppClient) printMissingSocketMsg() {
+func (c *socketClient) printMissingSocketMsg() {
 	fmt.Fprintf(os.Stderr, socketMissing, c.sockAddr)
 }
 
-type vppClient struct {
-	sockAddr string
+type socketClient struct {
+	sockAddr   string
+	clientName string
 
 	conn   *net.UnixConn
 	reader *bufio.Reader
@@ -102,50 +99,63 @@ type vppClient struct {
 	connectTimeout    time.Duration
 	disconnectTimeout time.Duration
 
-	cb           adapter.MsgCallback
+	msgCallback  adapter.MsgCallback
 	clientIndex  uint32
 	msgTable     map[string]uint16
 	sockDelMsgId uint16
 	writeMu      sync.Mutex
 
+	headerPool *sync.Pool
+
 	quit chan struct{}
 	wg   sync.WaitGroup
 }
 
-func NewVppClient(sockAddr string) *vppClient {
+func NewVppClient(sockAddr string) *socketClient {
 	if sockAddr == "" {
 		sockAddr = DefaultSocketName
 	}
-	return &vppClient{
+	return &socketClient{
 		sockAddr:          sockAddr,
+		clientName:        DefaultClientName,
 		connectTimeout:    DefaultConnectTimeout,
 		disconnectTimeout: DefaultDisconnectTimeout,
-		cb: func(msgID uint16, data []byte) {
-			Log.Warnf("no callback set, dropping message: ID=%v len=%d", msgID, len(data))
+		headerPool: &sync.Pool{New: func() interface{} {
+			return make([]byte, 16)
+		}},
+		msgCallback: func(msgID uint16, data []byte) {
+			log.Debugf("no callback set, dropping message: ID=%v len=%d", msgID, len(data))
 		},
 	}
 }
 
+// SetClientName sets a client name used for identification.
+func (c *socketClient) SetClientName(name string) {
+	c.clientName = name
+}
+
 // SetConnectTimeout sets timeout used during connecting.
-func (c *vppClient) SetConnectTimeout(t time.Duration) {
+func (c *socketClient) SetConnectTimeout(t time.Duration) {
 	c.connectTimeout = t
 }
 
 // SetDisconnectTimeout sets timeout used during disconnecting.
-func (c *vppClient) SetDisconnectTimeout(t time.Duration) {
+func (c *socketClient) SetDisconnectTimeout(t time.Duration) {
 	c.disconnectTimeout = t
 }
 
-func (c *vppClient) SetMsgCallback(cb adapter.MsgCallback) {
-	Log.Debug("SetMsgCallback")
-	c.cb = cb
+func (c *socketClient) SetMsgCallback(cb adapter.MsgCallback) {
+	log.Debug("SetMsgCallback")
+	c.msgCallback = cb
 }
 
-func (c *vppClient) checkLegacySocket() bool {
+const legacySocketName = "/run/vpp-api.sock"
+
+func (c *socketClient) checkLegacySocket() bool {
 	if c.sockAddr == legacySocketName {
 		return false
 	}
-	Log.Debugf("checking legacy socket: %s", legacySocketName)
+	log.Debugf("checking legacy socket: %s", legacySocketName)
 	// check if socket exists
 	if _, err := os.Stat(c.sockAddr); err == nil {
 		return false // socket exists
@@ -163,7 +173,7 @@ func (c *vppClient) checkLegacySocket() bool {
 }
 
 // WaitReady checks socket file existence and waits for it if necessary
-func (c *vppClient) WaitReady() error {
+func (c *socketClient) WaitReady() error {
 	// check if socket already exists
 	if _, err := os.Stat(c.sockAddr); err == nil {
 		return nil // socket exists, we are ready
@@ -182,7 +192,7 @@ func (c *vppClient) WaitReady() error {
 	}
 	defer func() {
 		if err := watcher.Close(); err != nil {
-			Log.Warnf("failed to close file watcher: %v", err)
+			log.Debugf("failed to close file watcher: %v", err)
 		}
 	}()
 
@@ -204,7 +214,7 @@ func (c *vppClient) WaitReady() error {
 			return e
 
 		case ev := <-watcher.Events:
-			Log.Debugf("watcher event: %+v", ev)
+			log.Debugf("watcher event: %+v", ev)
 			if ev.Name == c.sockAddr && (ev.Op&fsnotify.Create) == fsnotify.Create {
 				// socket created, we are ready
 				return nil
@@ -213,7 +223,7 @@ func (c *vppClient) WaitReady() error {
 	}
 }
 
-func (c *vppClient) Connect() error {
+func (c *socketClient) Connect() error {
 	c.checkLegacySocket()
 
 	// check if socket exists
@@ -229,7 +239,7 @@ func (c *vppClient) Connect() error {
 	}
 
 	if err := c.open(); err != nil {
-		c.disconnect()
+		_ = c.disconnect()
 		return err
 	}
 
@@ -240,23 +250,23 @@ func (c *vppClient) Connect() error {
 	return nil
 }
 
-func (c *vppClient) Disconnect() error {
+func (c *socketClient) Disconnect() error {
 	if c.conn == nil {
 		return nil
 	}
-	Log.Debugf("Disconnecting..")
+	log.Debugf("Disconnecting..")
 
 	close(c.quit)
 
 	if err := c.conn.CloseRead(); err != nil {
-		Log.Debugf("closing read failed: %v", err)
+		log.Debugf("closing readMsg failed: %v", err)
 	}
 
 	// wait for readerLoop to return
 	c.wg.Wait()
 
 	if err := c.close(); err != nil {
-		Log.Debugf("closing failed: %v", err)
+		log.Debugf("closing failed: %v", err)
 	}
 
 	if err := c.disconnect(); err != nil {
@@ -266,38 +276,40 @@ func (c *vppClient) Disconnect() error {
 	return nil
 }
 
-func (c *vppClient) connect(sockAddr string) error {
+const defaultBufferSize = 4096
+
+func (c *socketClient) connect(sockAddr string) error {
 	addr := &net.UnixAddr{Name: sockAddr, Net: "unix"}
 
-	Log.Debugf("Connecting to: %v", c.sockAddr)
+	log.Debugf("Connecting to: %v", c.sockAddr)
 
 	conn, err := net.DialUnix("unix", nil, addr)
 	if err != nil {
 		// we try different type of socket for backwards compatbility with VPP<=19.04
 		if strings.Contains(err.Error(), "wrong type for socket") {
 			addr.Net = "unixpacket"
-			Log.Debugf("%s, retrying connect with type unixpacket", err)
+			log.Debugf("%s, retrying connect with type unixpacket", err)
 			conn, err = net.DialUnix("unixpacket", nil, addr)
 		}
 		if err != nil {
-			Log.Debugf("Connecting to socket %s failed: %s", addr, err)
+			log.Debugf("Connecting to socket %s failed: %s", addr, err)
 			return err
 		}
 	}
 
 	c.conn = conn
-	Log.Debugf("Connected to socket (local addr: %v)", c.conn.LocalAddr().(*net.UnixAddr))
+	log.Debugf("Connected to socket (local addr: %v)", c.conn.LocalAddr().(*net.UnixAddr))
 
-	c.reader = bufio.NewReader(c.conn)
-	c.writer = bufio.NewWriter(c.conn)
+	c.reader = bufio.NewReaderSize(c.conn, defaultBufferSize)
+	c.writer = bufio.NewWriterSize(c.conn, defaultBufferSize)
 
 	return nil
 }
 
-func (c *vppClient) disconnect() error {
-	Log.Debugf("Closing socket")
+func (c *socketClient) disconnect() error {
+	log.Debugf("Closing socket")
 	if err := c.conn.Close(); err != nil {
-		Log.Debugln("Closing socket failed:", err)
+		log.Debugln("Closing socket failed:", err)
 		return err
 	}
 	return nil
@@ -309,44 +321,40 @@ const (
 	deleteMsgContext = byte(124)
 )
 
-func (c *vppClient) open() error {
-	msgCodec := new(codec.MsgCodec)
+func (c *socketClient) open() error {
+	var msgCodec codec.MsgCodec
 
-	req := &SockclntCreate{Name: ClientName}
+	// Request socket client create
+	req := &SockclntCreate{
+		Name: c.clientName,
+	}
 	msg, err := msgCodec.EncodeMsg(req, sockCreateMsgId)
 	if err != nil {
-		Log.Debugln("Encode error:", err)
+		log.Debugln("Encode  error:", err)
 		return err
 	}
 	// set non-0 context
 	msg[5] = createMsgContext
 
-	if err := c.write(msg); err != nil {
-		Log.Debugln("Write error: ", err)
-		return err
-	}
-
-	readDeadline := time.Now().Add(c.connectTimeout)
-	if err := c.conn.SetReadDeadline(readDeadline); err != nil {
+	if err := c.writeMsg(msg); err != nil {
+		log.Debugln("Write error: ", err)
 		return err
 	}
-	msgReply, err := c.read()
+	msgReply, err := c.readMsgTimeout(nil, c.connectTimeout)
 	if err != nil {
-		Log.Println("Read error:", err)
-		return err
-	}
-	// reset read deadline
-	if err := c.conn.SetReadDeadline(time.Time{}); err != nil {
+		log.Println("Read error:", err)
 		return err
 	}
 
 	reply := new(SockclntCreateReply)
 	if err := msgCodec.DecodeMsg(msgReply, reply); err != nil {
-		Log.Println("Decode error:", err)
+		log.Println("Decoding sockclnt_create_reply failed:", err)
 		return err
+	} else if reply.Response != 0 {
+		return fmt.Errorf("sockclnt_create_reply: response error (%d)", reply.Response)
 	}
 
-	Log.Debugf("SockclntCreateReply: Response=%v Index=%v Count=%v",
+	log.Debugf("SockclntCreateReply: Response=%v Index=%v Count=%v",
 		reply.Response, reply.Index, reply.Count)
 
 	c.clientIndex = reply.Index
@@ -358,15 +366,15 @@ func (c *vppClient) open() error {
 		if strings.HasPrefix(name, "sockclnt_delete_") {
 			c.sockDelMsgId = x.Index
 		}
-		if DebugMsgIds {
-			Log.Debugf(" - %4d: %q", x.Index, name)
+		if debugMsgIds {
+			log.Debugf(" - %4d: %q", x.Index, name)
 		}
 	}
 
 	return nil
 }
 
-func (c *vppClient) close() error {
+func (c *socketClient) close() error {
 	msgCodec := new(codec.MsgCodec)
 
 	req := &SockclntDelete{
@@ -374,133 +382,148 @@ func (c *vppClient) close() error {
 	}
 	msg, err := msgCodec.EncodeMsg(req, c.sockDelMsgId)
 	if err != nil {
-		Log.Debugln("Encode error:", err)
+		log.Debugln("Encode error:", err)
 		return err
 	}
 	// set non-0 context
 	msg[5] = deleteMsgContext
 
-	Log.Debugf("sending socklntDel (%d byes): % 0X", len(msg), msg)
-	if err := c.write(msg); err != nil {
-		Log.Debugln("Write error: ", err)
-		return err
-	}
+	log.Debugf("sending socklntDel (%d bytes): % 0X", len(msg), msg)
 
-	readDeadline := time.Now().Add(c.disconnectTimeout)
-	if err := c.conn.SetReadDeadline(readDeadline); err != nil {
+	if err := c.writeMsg(msg); err != nil {
+		log.Debugln("Write error: ", err)
 		return err
 	}
-	msgReply, err := c.read()
+
+	msgReply, err := c.readMsgTimeout(nil, c.disconnectTimeout)
 	if err != nil {
-		Log.Debugln("Read error:", err)
 		if nerr, ok := err.(net.Error); ok && nerr.Timeout() {
 			// we accept timeout for reply
 			return nil
 		}
-		return err
-	}
-	// reset read deadline
-	if err := c.conn.SetReadDeadline(time.Time{}); err != nil {
+		log.Debugln("Read error:", err)
 		return err
 	}
 
 	reply := new(SockclntDeleteReply)
 	if err := msgCodec.DecodeMsg(msgReply, reply); err != nil {
-		Log.Debugln("Decode error:", err)
+		log.Debugln("Decoding sockclnt_delete_reply failed:", err)
 		return err
+	} else if reply.Response != 0 {
+		return fmt.Errorf("sockclnt_delete_reply: response error (%d)", reply.Response)
 	}
 
-	Log.Debugf("SockclntDeleteReply: Response=%v", reply.Response)
-
 	return nil
 }
 
-func (c *vppClient) GetMsgID(msgName string, msgCrc string) (uint16, error) {
-	msg := msgName + "_" + msgCrc
-	msgID, ok := c.msgTable[msg]
-	if !ok {
-		return 0, &adapter.UnknownMsgError{msgName, msgCrc}
+func (c *socketClient) GetMsgID(msgName string, msgCrc string) (uint16, error) {
+	if msgID, ok := c.msgTable[msgName+"_"+msgCrc]; ok {
+		return msgID, nil
+	}
+	return 0, &adapter.UnknownMsgError{
+		MsgName: msgName,
+		MsgCrc:  msgCrc,
 	}
-	return msgID, nil
-}
-
-type reqHeader struct {
-	// MsgID uint16
-	ClientIndex uint32
-	Context     uint32
 }
 
-func (c *vppClient) SendMsg(context uint32, data []byte) error {
-	h := &reqHeader{
-		ClientIndex: c.clientIndex,
-		Context:     context,
-	}
-	buf := new(bytes.Buffer)
-	if err := struc.Pack(buf, h); err != nil {
-		return err
+func (c *socketClient) SendMsg(context uint32, data []byte) error {
+	if len(data) < 10 {
+		return fmt.Errorf("invalid message data, length must be at least 10 bytes")
 	}
-	copy(data[2:], buf.Bytes())
+	setMsgRequestHeader(data, c.clientIndex, context)
 
-	Log.Debugf("sendMsg (%d) context=%v client=%d: data: % 02X", len(data), context, c.clientIndex, data)
+	if debug {
+		log.Debugf("sendMsg (%d) context=%v client=%d: % 02X", len(data), context, c.clientIndex, data)
+	}
 
-	if err := c.write(data); err != nil {
-		Log.Debugln("write error: ", err)
+	if err := c.writeMsg(data); err != nil {
+		log.Debugln("writeMsg error: ", err)
 		return err
 	}
 
 	return nil
 }
 
-func (c *vppClient) write(msg []byte) error {
-	h := &msgheader{
-		DataLen: uint32(len(msg)),
+// setMsgRequestHeader sets client index and context in the message request header
+//
+// Message request has following structure:
+//
+//    type msgRequestHeader struct {
+//        MsgID       uint16
+//        ClientIndex uint32
+//        Context     uint32
+//    }
+//
+func setMsgRequestHeader(data []byte, clientIndex, context uint32) {
+	// message ID is already set
+	binary.BigEndian.PutUint32(data[2:6], clientIndex)
+	binary.BigEndian.PutUint32(data[6:10], context)
+}
+
+func (c *socketClient) writeMsg(msg []byte) error {
+	// we lock to prevent mixing multiple message writes
+	c.writeMu.Lock()
+	defer c.writeMu.Unlock()
+
+	header := c.headerPool.Get().([]byte)
+	err := writeMsgHeader(c.writer, header, len(msg))
+	if err != nil {
+		return err
 	}
-	buf := new(bytes.Buffer)
-	if err := struc.Pack(buf, h); err != nil {
+	c.headerPool.Put(header)
+
+	if err := writeMsgData(c.writer, msg, c.writer.Size()); err != nil {
 		return err
 	}
-	header := buf.Bytes()
 
-	// we lock to prevent mixing multiple message sends
-	c.writeMu.Lock()
-	defer c.writeMu.Unlock()
+	if err := c.writer.Flush(); err != nil {
+		return err
+	}
+
+	log.Debugf(" -- writeMsg done")
+
+	return nil
+}
+
+func writeMsgHeader(w io.Writer, header []byte, dataLen int) error {
+	binary.BigEndian.PutUint32(header[8:12], uint32(dataLen))
 
-	if n, err := c.writer.Write(header); err != nil {
+	n, err := w.Write(header)
+	if err != nil {
 		return err
-	} else {
-		Log.Debugf(" - header sent (%d/%d): % 0X", n, len(header), header)
+	}
+	if debug {
+		log.Debugf(" - header sent (%d/%d): % 0X", n, len(header), header)
 	}
 
-	writerSize := c.writer.Size()
+	return nil
+}
+
+func writeMsgData(w io.Writer, msg []byte, writerSize int) error {
 	for i := 0; i <= len(msg)/writerSize; i++ {
 		x := i*writerSize + writerSize
 		if x > len(msg) {
 			x = len(msg)
 		}
-		Log.Debugf(" - x=%v i=%v len=%v mod=%v", x, i, len(msg), len(msg)/writerSize)
-		if n, err := c.writer.Write(msg[i*writerSize : x]); err != nil {
+		if debug {
+			log.Debugf(" - x=%v i=%v len=%v mod=%v", x, i, len(msg), len(msg)/writerSize)
+		}
+		n, err := w.Write(msg[i*writerSize : x])
+		if err != nil {
 			return err
-		} else {
-			Log.Debugf(" - msg sent x=%d (%d/%d): % 0X", x, n, len(msg), msg)
+		}
+		if debug {
+			log.Debugf(" - data sent x=%d (%d/%d): % 0X", x, n, len(msg), msg)
 		}
 	}
-	if err := c.writer.Flush(); err != nil {
-		return err
-	}
-
-	Log.Debugf(" -- write done")
-
 	return nil
 }
 
-type msgHeader struct {
-	MsgID   uint16
-	Context uint32
-}
-
-func (c *vppClient) readerLoop() {
+func (c *socketClient) readerLoop() {
 	defer c.wg.Done()
-	defer Log.Debugf("reader quit")
+	defer log.Debugf("reader loop done")
+
+	var buf [8192]byte
 
 	for {
 		select {
@@ -509,72 +532,118 @@ func (c *vppClient) readerLoop() {
 		default:
 		}
 
-		msg, err := c.read()
+		msg, err := c.readMsg(buf[:])
 		if err != nil {
 			if isClosedError(err) {
 				return
 			}
-			Log.Debugf("read failed: %v", err)
+			log.Debugf("readMsg error: %v", err)
 			continue
 		}
 
-		h := new(msgHeader)
-		if err := struc.Unpack(bytes.NewReader(msg), h); err != nil {
-			Log.Debugf("unpacking header failed: %v", err)
-			continue
+		msgID, context := getMsgReplyHeader(msg)
+		if debug {
+			log.Debugf("recvMsg (%d) msgID=%d context=%v", len(msg), msgID, context)
 		}
 
-		Log.Debugf("recvMsg (%d) msgID=%d context=%v", len(msg), h.MsgID, h.Context)
-		c.cb(h.MsgID, msg)
+		c.msgCallback(msgID, msg)
 	}
 }
 
-type msgheader struct {
-	Q               int    `struc:"uint64"`
-	DataLen         uint32 `struc:"uint32"`
-	GcMarkTimestamp uint32 `struc:"uint32"`
+// getMsgReplyHeader gets message ID and context from the message reply header
+//
+// Message reply has following structure:
+//
+//    type msgReplyHeader struct {
+//        MsgID       uint16
+//        Context     uint32
+//    }
+//
+func getMsgReplyHeader(msg []byte) (msgID uint16, context uint32) {
+	msgID = binary.BigEndian.Uint16(msg[0:2])
+	context = binary.BigEndian.Uint32(msg[2:6])
+	return
 }
 
-func (c *vppClient) read() ([]byte, error) {
-	Log.Debug(" reading next msg..")
+func (c *socketClient) readMsgTimeout(buf []byte, timeout time.Duration) ([]byte, error) {
+	// set read deadline
+	readDeadline := time.Now().Add(timeout)
+	if err := c.conn.SetReadDeadline(readDeadline); err != nil {
+		return nil, err
+	}
 
-	header := make([]byte, 16)
+	// read message
+	msgReply, err := c.readMsg(buf)
+	if err != nil {
+		return nil, err
+	}
 
-	n, err := io.ReadAtLeast(c.reader, header, 16)
+	// reset read deadline
+	if err := c.conn.SetReadDeadline(time.Time{}); err != nil {
+		return nil, err
+	}
+
+	return msgReply, nil
+}
+
+func (c *socketClient) readMsg(buf []byte) ([]byte, error) {
+	log.Debug("reading msg..")
+
+	header := c.headerPool.Get().([]byte)
+	msgLen, err := readMsgHeader(c.reader, header)
 	if err != nil {
 		return nil, err
 	}
+	c.headerPool.Put(header)
+
+	msg, err := readMsgData(c.reader, buf, msgLen)
+
+	log.Debugf(" -- readMsg done (buffered: %d)", c.reader.Buffered())
+
+	return msg, nil
+}
+
+func readMsgHeader(r io.Reader, header []byte) (int, error) {
+	n, err := io.ReadAtLeast(r, header, 16)
+	if err != nil {
+		return 0, err
+	}
 	if n == 0 {
-		Log.Debugln("zero bytes header")
-		return nil, nil
+		log.Debugln("zero bytes header")
+		return 0, nil
 	} else if n != 16 {
-		Log.Debugf("invalid header data (%d): % 0X", n, header[:n])
-		return nil, fmt.Errorf("invalid header (expected 16 bytes, got %d)", n)
+		log.Debugf("invalid header (%d bytes): % 0X", n, header[:n])
+		return 0, fmt.Errorf("invalid header (expected 16 bytes, got %d)", n)
 	}
-	Log.Debugf(" read header %d bytes: % 0X", n, header)
 
-	h := &msgheader{}
-	if err := struc.Unpack(bytes.NewReader(header[:]), h); err != nil {
-		return nil, err
-	}
-	Log.Debugf(" - decoded header: %+v", h)
+	dataLen := binary.BigEndian.Uint32(header[8:12])
 
-	msgLen := int(h.DataLen)
-	msg := make([]byte, msgLen)
+	return int(dataLen), nil
+}
+
+func readMsgData(r io.Reader, buf []byte, dataLen int) ([]byte, error) {
+	var msg []byte
+	if buf == nil || len(buf) < dataLen {
+		msg = make([]byte, dataLen)
+	} else {
+		msg = buf[0:dataLen]
+	}
 
-	n, err = c.reader.Read(msg)
+	n, err := r.Read(msg)
 	if err != nil {
 		return nil, err
 	}
-	Log.Debugf(" - read msg %d bytes (%d buffered) % 0X", n, c.reader.Buffered(), msg[:n])
+	if debug {
+		log.Debugf(" - read data (%d bytes): % 0X", n, msg[:n])
+	}
 
-	if msgLen > n {
-		remain := msgLen - n
-		Log.Debugf("continue read for another %d bytes", remain)
+	if dataLen > n {
+		remain := dataLen - n
+		log.Debugf("continue reading remaining %d bytes", remain)
 		view := msg[n:]
 
 		for remain > 0 {
-			nbytes, err := c.reader.Read(view)
+			nbytes, err := r.Read(view)
 			if err != nil {
 				return nil, err
 			} else if nbytes == 0 {
@@ -582,19 +651,17 @@ func (c *vppClient) read() ([]byte, error) {
 			}
 
 			remain -= nbytes
-			Log.Debugf("another data received: %d bytes (remain: %d)", nbytes, remain)
+			log.Debugf("another data received: %d bytes (remain: %d)", nbytes, remain)
 
 			view = view[nbytes:]
 		}
 	}
 
-	Log.Debugf(" -- read done (buffered: %d)", c.reader.Buffered())
-
 	return msg, nil
 }
 
 func isClosedError(err error) bool {
-	if err == io.EOF {
+	if errors.Is(err, io.EOF) {
 		return true
 	}
 	return strings.HasSuffix(err.Error(), "use of closed network connection")
diff --git a/api/binapi.go b/api/binapi.go
index d933612..96eb3bf 100644
--- a/api/binapi.go
+++ b/api/binapi.go
@@ -91,42 +91,47 @@ type Channel interface {
 	// It will return an error if any of the given messages are not compatible.
 	CheckCompatiblity(msgs ...Message) error
 
-	// Close closes the API channel and releases all API channel-related resources in the ChannelProvider.
+	// Close closes the API channel and releases all API channel-related resources
+	// in the ChannelProvider.
 	Close()
 }
 
 // RequestCtx is helper interface which allows to receive reply on request.
 type RequestCtx interface {
-	// ReceiveReply receives a reply from VPP (blocks until a reply is delivered from VPP, or until an error occurs).
-	// The reply will be decoded into the msg argument. Error will be returned if the response cannot be received or decoded.
+	// ReceiveReply receives a reply from VPP (blocks until a reply is delivered
+	// from VPP, or until an error occurs). The reply will be decoded into the msg
+	// argument. Error will be returned if the response cannot be received or decoded.
 	ReceiveReply(msg Message) error
 }
 
 // MultiRequestCtx is helper interface which allows to receive reply on multi-request.
 type MultiRequestCtx interface {
-	// ReceiveReply receives a reply from VPP (blocks until a reply is delivered from VPP, or until an error occurs).
-	// The reply will be decoded into the msg argument. If the last reply has been already consumed, lastReplyReceived is
-	// set to true. Do not use the message itself if lastReplyReceived is true - it won't be filled with actual data.
-	// Error will be returned if the response cannot be received or decoded.
+	// ReceiveReply receives a reply from VPP (blocks until a reply is delivered
+	// from VPP, or until an error occurs).The reply will be decoded into the msg
+	// argument. If the last reply has been already consumed, lastReplyReceived is
+	// set to true. Do not use the message itself if lastReplyReceived is
+	// true - it won't be filled with actual data.Error will be returned if the
+	// response cannot be received or decoded.
 	ReceiveReply(msg Message) (lastReplyReceived bool, err error)
 }
 
-// SubscriptionCtx is helper interface which allows to control subscription for notification events.
+// SubscriptionCtx is helper interface which allows to control subscription for
+// notification events.
 type SubscriptionCtx interface {
-	// Unsubscribe unsubscribes from receiving the notifications tied to the subscription context.
+	// Unsubscribe unsubscribes from receiving the notifications tied to the
+	// subscription context.
 	Unsubscribe() error
 }
 
 // CompatibilityError is the error type usually returned by CheckCompatibility
-// method of Channel. It describes all of the incompatible messages.
+// method of Channel. It contains list of all the compatible/incompatible messages.
 type CompatibilityError struct {
-	// IncompatibleMessages is the list of all messages
-	// that failed compatibility check.
+	CompatibleMessages   []string
 	IncompatibleMessages []string
 }
 
 func (c *CompatibilityError) Error() string {
-	return fmt.Sprintf("%d incompatible messages: %v", len(c.IncompatibleMessages), c.IncompatibleMessages)
+	return fmt.Sprintf("%d/%d messages incompatible", len(c.IncompatibleMessages), len(c.CompatibleMessages)+len(c.IncompatibleMessages))
 }
 
 var (
@@ -155,6 +160,6 @@ func GetRegisteredMessageTypes() map[reflect.Type]string {
 	return registeredMessageTypes
 }
 
-// GoVppAPIPackageIsVersion1 is referenced from generated binapi files
+// GoVppAPIPackageIsVersionX is referenced from generated binapi files
 // to assert that that code is compatible with this version of the GoVPP api package.
 const GoVppAPIPackageIsVersion1 = true
diff --git a/codec/msg_codec.go b/codec/msg_codec.go
index 67628a4..3f60cae 100644
--- a/codec/msg_codec.go
+++ b/codec/msg_codec.go
@@ -20,8 +20,9 @@ import (
 	"fmt"
 	"reflect"
 
-	"git.fd.io/govpp.git/api"
 	"github.com/lunixbochs/struc"
+
+	"git.fd.io/govpp.git/api"
 )
 
 // MsgCodec provides encoding and decoding functionality of `api.Message` structs into/from
@@ -65,7 +66,7 @@ func (*MsgCodec) EncodeMsg(msg api.Message, msgID uint16) (data []byte, err erro
 			if err, ok = r.(error); !ok {
 				err = fmt.Errorf("%v", r)
 			}
-			err = fmt.Errorf("panic occurred: %v", err)
+			err = fmt.Errorf("panic occurred during encoding message %s: %v", msg.GetMessageName(), err)
 		}
 	}()
 
@@ -101,11 +102,22 @@ func (*MsgCodec) EncodeMsg(msg api.Message, msgID uint16) (data []byte, err erro
 }
 
 // DecodeMsg decodes binary-encoded data of a message into provided `Message` structure.
-func (*MsgCodec) DecodeMsg(data []byte, msg api.Message) error {
+func (*MsgCodec) DecodeMsg(data []byte, msg api.Message) (err error) {
 	if msg == nil {
 		return errors.New("nil message passed in")
 	}
 
+	// try to recover panic which might possibly occur
+	defer func() {
+		if r := recover(); r != nil {
+			var ok bool
+			if err, ok = r.(error); !ok {
+				err = fmt.Errorf("%v", r)
+			}
+			err = fmt.Errorf("panic occurred during decoding message %s: %v", msg.GetMessageName(), err)
+		}
+	}()
+
 	var header interface{}
 
 	// check which header is expected
@@ -123,7 +135,7 @@ func (*MsgCodec) DecodeMsg(data []byte, msg api.Message) error {
 	buf := bytes.NewReader(data)
 
 	// decode message header
-	if err := struc.Unpack(buf, header); err != nil {
+	if err = struc.Unpack(buf, header); err != nil {
 		return fmt.Errorf("failed to decode message header: %+v, error: %v", header, err)
 	}
 
diff --git a/core/channel.go b/core/channel.go
index 363a267..8479d6a 100644
--- a/core/channel.go
+++ b/core/channel.go
@@ -37,6 +37,8 @@ type MessageCodec interface {
 	EncodeMsg(msg api.Message, msgID uint16) ([]byte, error)
 	// DecodeMsg decodes binary-encoded data of a message into provided Message structure.
 	DecodeMsg(data []byte, msg api.Message) error
+	// DecodeMsgContext decodes context from message data.
+	DecodeMsgContext(data []byte, msg api.Message) (context uint32, err error)
 }
 
 // MessageIdentifier provides identification of generated API messages.
@@ -84,7 +86,7 @@ type subscriptionCtx struct {
 	msgFactory func() api.Message // function that returns a new instance of the specific message that is expected as a notification
 }
 
-// channel is the main communication interface with govpp core. It contains four Go channels, one for sending the requests
+// Channel is the main communication interface with govpp core. It contains four Go channels, one for sending the requests
 // to VPP, one for receiving the replies from it and the same set for notifications. The user can access the Go channels
 // via methods provided by Channel interface in this package. Do not use the same channel from multiple goroutines
 // concurrently, otherwise the responses could mix! Use multiple channels instead.
@@ -150,13 +152,13 @@ func (ch *Channel) CheckCompatiblity(msgs ...api.Message) error {
 		_, err := ch.msgIdentifier.GetMessageID(msg)
 		if err != nil {
 			if uerr, ok := err.(*adapter.UnknownMsgError); ok {
-				m := fmt.Sprintf("%s_%s", uerr.MsgName, uerr.MsgCrc)
-				comperr.IncompatibleMessages = append(comperr.IncompatibleMessages, m)
+				comperr.IncompatibleMessages = append(comperr.IncompatibleMessages, getMsgID(uerr.MsgName, uerr.MsgCrc))
 				continue
 			}
 			// other errors return immediatelly
 			return err
 		}
+		comperr.CompatibleMessages = append(comperr.CompatibleMessages, getMsgNameWithCrc(msg))
 	}
 	if len(comperr.IncompatibleMessages) == 0 {
 		return nil
@@ -234,6 +236,8 @@ func (sub *subscriptionCtx) Unsubscribe() error {
 
 	for i, item := range sub.ch.conn.subscriptions[sub.msgID] {
 		if item == sub {
+			// close notification channel
+			close(sub.ch.conn.subscriptions[sub.msgID][i].notifChan)
 			// remove i-th item in the slice
 			sub.ch.conn.subscriptions[sub.msgID] = append(sub.ch.conn.subscriptions[sub.msgID][:i], sub.ch.conn.subscriptions[sub.msgID][i+1:]...)
 			return nil
@@ -328,9 +332,9 @@ func (ch *Channel) processReply(reply *vppReply, expSeqNum uint16, msg api.Messa
 			msgNameCrc = getMsgNameWithCrc(replyMsg)
 		}
 
-		err = fmt.Errorf("received invalid message ID (seqNum=%d), expected %d (%s), but got %d (%s) "+
+		err = fmt.Errorf("received unexpected message (seqNum=%d), expected %s (ID %d), but got %s (ID %d) "+
 			"(check if multiple goroutines are not sharing single GoVPP channel)",
-			reply.seqNum, expMsgID, msg.GetMessageName(), reply.msgID, msgNameCrc)
+			reply.seqNum, msg.GetMessageName(), expMsgID, msgNameCrc, reply.msgID)
 		return
 	}
 
diff --git a/core/channel_test.go b/core/channel_test.go
index b8d07b5..6775519 100644
--- a/core/channel_test.go
+++ b/core/channel_test.go
@@ -466,5 +466,5 @@ func TestInvalidMessageID(t *testing.T) {
 	// second should fail with error invalid message ID
 	err = ctx.ch.SendRequest(&ControlPing{}).ReceiveReply(&ControlPingReply{})
 	Expect(err).Should(HaveOccurred())
-	Expect(err.Error()).To(ContainSubstring("invalid message ID"))
+	Expect(err.Error()).To(ContainSubstring("unexpected message"))
 }
diff --git a/core/connection.go b/core/connection.go
index 264ec43..917f1cb 100644
--- a/core/connection.go
+++ b/core/connection.go
@@ -95,7 +95,7 @@ type Connection struct {
 
 	vppConnected uint32 // non-zero if the adapter is connected to VPP
 
-	codec  *codec.MsgCodec        // message codec
+	codec  MessageCodec           // message codec
 	msgIDs map[string]uint16      // map of message IDs indexed by message name + CRC
 	msgMap map[uint16]api.Message // map of messages indexed by message ID
 
@@ -374,7 +374,11 @@ func (c *Connection) healthCheckLoop(connChan chan ConnectionEvent) {
 }
 
 func getMsgNameWithCrc(x api.Message) string {
-	return x.GetMessageName() + "_" + x.GetCrcString()
+	return getMsgID(x.GetMessageName(), x.GetCrcString())
+}
+
+func getMsgID(name, crc string) string {
+	return name + "_" + crc
 }
 
 func getMsgFactory(msg api.Message) func() api.Message {
@@ -425,9 +429,14 @@ func (c *Connection) retrieveMessageIDs() (err error) {
 
 	var n int
 	for name, msg := range msgs {
+		typ := reflect.TypeOf(msg).Elem()
+		path := fmt.Sprintf("%s.%s", typ.PkgPath(), typ.Name())
+
 		msgID, err := c.GetMessageID(msg)
 		if err != nil {
-			log.Debugf("retrieving msgID for %s failed: %v", name, err)
+			if debugMsgIDs {
+				log.Debugf("retrieving message ID for %s failed: %v", path, err)
+			}
 			continue
 		}
 		n++
@@ -444,7 +453,8 @@ func (c *Connection) retrieveMessageIDs() (err error) {
 			log.Debugf("message %q (%s) has ID: %d", name, getMsgNameWithCrc(msg), msgID)
 		}
 	}
-	log.Debugf("retrieved %d/%d msgIDs (took %s)", n, len(msgs), time.Since(t))
+	log.WithField("took", time.Since(t)).
+		Debugf("retrieved IDs for %d messages (registered %d)", n, len(msgs))
 
 	return nil
 }
diff --git a/core/log.go b/core/log.go
index 5960d6b..dea6cbb 100644
--- a/core/log.go
+++ b/core/log.go
@@ -2,32 +2,35 @@ package core
 
 import (
 	"os"
+	"strings"
 
-	logger "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
 )
 
 var (
 	debug       = os.Getenv("DEBUG_GOVPP") != ""
-	debugMsgIDs = os.Getenv("DEBUG_GOVPP_MSGIDS") != ""
+	debugMsgIDs = strings.Contains(os.Getenv("DEBUG_GOVPP"), "msgid")
 
-	log = logger.New() // global logger
+	log = logrus.New()
 )
 
-// init initializes global logger, which logs debug level messages to stdout.
+// init initializes global logger
 func init() {
-	log.Out = os.Stdout
+	log.Formatter = &logrus.TextFormatter{
+		EnvironmentOverrideColors: true,
+	}
 	if debug {
-		log.Level = logger.DebugLevel
-		log.Debugf("govpp/core: debug mode enabled")
+		log.Level = logrus.DebugLevel
+		log.Debugf("govpp: debug level enabled")
 	}
 }
 
 // SetLogger sets global logger to l.
-func SetLogger(l *logger.Logger) {
+func SetLogger(l *logrus.Logger) {
 	log = l
 }
 
 // SetLogLevel sets global logger level to lvl.
-func SetLogLevel(lvl logger.Level) {
+func SetLogLevel(lvl logrus.Level) {
 	log.Level = lvl
 }
diff --git a/core/request_handler.go b/core/request_handler.go
index ddd5307..e272c6f 100644
--- a/core/request_handler.go
+++ b/core/request_handler.go
@@ -17,10 +17,13 @@ package core
 import (
 	"errors"
 	"fmt"
+	"reflect"
 	"sync/atomic"
 	"time"
 
 	logger "github.com/sirupsen/logrus"
+
+	"git.fd.io/govpp.git/api"
 )
 
 var ReplyChannelTimeout = time.Millisecond * 100
@@ -93,7 +96,7 @@ func (c *Connection) processRequest(ch *Channel, req *vppRequest) error {
 			"msg_size": len(data),
 			"seq_num":  req.seqNum,
 			"msg_crc":  req.msg.GetCrcString(),
-		}).Debugf("==> govpp send: %s: %+v", req.msg.GetMessageName(), req.msg)
+		}).Debugf("--> govpp SEND: %s %+v", req.msg.GetMessageName(), req.msg)
 	}
 
 	// send the request to VPP
@@ -118,7 +121,7 @@ func (c *Connection) processRequest(ch *Channel, req *vppRequest) error {
 			"msg_id":   c.pingReqID,
 			"msg_size": len(pingData),
 			"seq_num":  req.seqNum,
-		}).Debug("--> sending control ping")
+		}).Debug(" -> sending control ping")
 
 		if err := c.vppClient.SendMsg(context, pingData); err != nil {
 			log.WithFields(logger.Fields{
@@ -156,7 +159,16 @@ func (c *Connection) msgCallback(msgID uint16, data []byte) {
 	}
 
 	chanID, isMulti, seqNum := unpackRequestContext(context)
+
 	if log.Level == logger.DebugLevel { // for performance reasons - logrus does some processing even if debugs are disabled
+		msg = reflect.New(reflect.TypeOf(msg).Elem()).Interface().(api.Message)
+
+		// decode the message
+		if err = c.codec.DecodeMsg(data, msg); err != nil {
+			err = fmt.Errorf("decoding message failed: %w", err)
+			return
+		}
+
 		log.WithFields(logger.Fields{
 			"context":  context,
 			"msg_id":   msgID,
@@ -165,7 +177,7 @@ func (c *Connection) msgCallback(msgID uint16, data []byte) {
 			"is_multi": isMulti,
 			"seq_num":  seqNum,
 			"msg_crc":  msg.GetCrcString(),
-		}).Debugf("<== govpp recv: %s", msg.GetMessageName())
+		}).Debugf("<-- govpp RECEIVE: %s %+v", msg.GetMessageName(), msg)
 	}
 
 	if context == 0 || c.isNotificationMessage(msgID) {
@@ -210,7 +222,7 @@ func (c *Connection) msgCallback(msgID uint16, data []byte) {
 func sendReply(ch *Channel, reply *vppReply) {
 	select {
 	case ch.replyChan <- reply:
-		// reply sent successfully
+	// reply sent successfully
 	case <-time.After(ReplyChannelTimeout):
 		// receiver still not ready
 		log.WithFields(logger.Fields{
diff --git a/examples/perf-bench/perf-bench.go b/examples/perf-bench/perf-bench.go
index f48c154..81d183c 100644
--- a/examples/perf-bench/perf-bench.go
+++ b/examples/perf-bench/perf-bench.go
@@ -20,6 +20,7 @@ import (
 	"flag"
 	"fmt"
 	"log"
+	"os"
 	"time"
 
 	"github.com/pkg/profile"
@@ -39,14 +40,14 @@ const (
 
 func main() {
 	// parse optional flags
-	var sync, prof bool
+	var sync bool
 	var cnt int
-	var sock string
+	var sock, prof string
 	flag.BoolVar(&sync, "sync", false, "run synchronous perf test")
-	flag.StringVar(&sock, "socket", socketclient.DefaultSocketName, "Path to VPP API socket")
-	flag.String("socket", statsclient.DefaultSocketName, "Path to VPP stats socket")
+	flag.StringVar(&sock, "api-socket", socketclient.DefaultSocketName, "Path to VPP API socket")
+	flag.String("stats-socket", statsclient.DefaultSocketName, "Path to VPP stats socket")
 	flag.IntVar(&cnt, "count", 0, "count of requests to be sent to VPP")
-	flag.BoolVar(&prof, "prof", false, "generate profile data")
+	flag.StringVar(&prof, "prof", "", "enable profiling mode [mem, cpu]")
 	flag.Parse()
 
 	if cnt == 0 {
@@ -58,8 +59,16 @@ func main() {
 		}
 	}
 
-	if prof {
-		defer profile.Start().Stop()
+	switch prof {
+	case "mem":
+		defer profile.Start(profile.MemProfile, profile.MemProfileRate(1)).Stop()
+	case "cpu":
+		defer profile.Start(profile.CPUProfile).Stop()
+	case "":
+	default:
+		fmt.Printf("invalid profiling mode: %q\n", prof)
+		flag.Usage()
+		os.Exit(1)
 	}
 
 	a := socketclient.NewVppClient(sock)
diff --git a/examples/simple-client/simple_client.go b/examples/simple-client/simple_client.go
index 6d96ca8..fe7c109 100644
--- a/examples/simple-client/simple_client.go
+++ b/examples/simple-client/simple_client.go
@@ -65,20 +65,22 @@ func main() {
 	}
 	defer ch.Close()
 
+	if err := ch.CheckCompatiblity(vpe.AllMessages()...); err != nil {
+		log.Fatal(err)
+	}
+
 	vppVersion(ch)
 
 	if err := ch.CheckCompatiblity(interfaces.AllMessages()...); err != nil {
 		log.Fatal(err)
 	}
 
-	createLoopback(ch)
-	createLoopback(ch)
+	idx := createLoopback(ch)
 	interfaceDump(ch)
 
-	addIPAddress(ch)
-	ipAddressDump(ch)
-
-	interfaceNotifications(ch)
+	addIPAddress(ch, idx)
+	ipAddressDump(ch, idx)
+	interfaceNotifications(ch, idx)
 
 	if len(Errors) > 0 {
 		fmt.Printf("finished with %d errors\n", len(Errors))
@@ -109,11 +111,12 @@ func vppVersion(ch api.Channel) {
 	fmt.Printf("reply: %+v\n", reply)
 
 	fmt.Printf("VPP version: %q\n", cleanString(reply.Version))
-	fmt.Println("ok")
+	fmt.Println("OK")
+	fmt.Println()
 }
 
 // createLoopback sends request to create loopback interface.
-func createLoopback(ch api.Channel) {
+func createLoopback(ch api.Channel) interfaces.InterfaceIndex {
 	fmt.Println("Creating loopback interface")
 
 	req := &interfaces.CreateLoopback{}
@@ -121,48 +124,54 @@ func createLoopback(ch api.Channel) {
 
 	if err := ch.SendRequest(req).ReceiveReply(reply); err != nil {
 		logError(err, "creating loopback interface")
-		return
+		return 0
 	}
 	fmt.Printf("reply: %+v\n", reply)
 
-	fmt.Printf("loopback interface index: %v\n", reply.SwIfIndex)
+	fmt.Printf("interface index: %v\n", reply.SwIfIndex)
 	fmt.Println("OK")
+	fmt.Println()
+
+	return reply.SwIfIndex
 }
 
 // interfaceDump shows an example of multipart request (multiple replies are expected).
 func interfaceDump(ch api.Channel) {
 	fmt.Println("Dumping interfaces")
 
+	n := 0
 	reqCtx := ch.SendMultiRequest(&interfaces.SwInterfaceDump{})
 	for {
 		msg := &interfaces.SwInterfaceDetails{}
 		stop, err := reqCtx.ReceiveReply(msg)
+		if stop {
+			break
+		}
 		if err != nil {
 			logError(err, "dumping interfaces")
 			return
 		}
-		if stop {
-			break
-		}
-		fmt.Printf(" - interface: %+v\n", msg)
+		n++
+		fmt.Printf(" - interface #%d: %+v\n", n, msg)
 	}
 
 	fmt.Println("OK")
+	fmt.Println()
 }
 
 // addIPAddress sends request to add IP address to interface.
-func addIPAddress(ch api.Channel) {
-	fmt.Println("Adding IP address to interface")
+func addIPAddress(ch api.Channel, index interfaces.InterfaceIndex) {
+	fmt.Printf("Adding IP address to interface to interface index %d\n", index)
 
 	req := &interfaces.SwInterfaceAddDelAddress{
-		SwIfIndex: 1,
+		SwIfIndex: index,
 		IsAdd:     true,
 		Prefix: ip_types.AddressWithPrefix{
 			Address: interfaces.Address{
 				Af: ip_types.ADDRESS_IP4,
-				Un: ip_types.AddressUnionIP4(interfaces.IP4Address{10, 10, 0, 1}),
+				Un: ip_types.AddressUnionIP4(interfaces.IP4Address{10, 10, 0, uint8(index)}),
 			},
-			Len: 24,
+			Len: 32,
 		},
 	}
 	reply := &interfaces.SwInterfaceAddDelAddressReply{}
@@ -174,13 +183,14 @@ func addIPAddress(ch api.Channel) {
 	fmt.Printf("reply: %+v\n", reply)
 
 	fmt.Println("OK")
+	fmt.Println()
 }
 
-func ipAddressDump(ch api.Channel) {
-	fmt.Println("Dumping IP addresses")
+func ipAddressDump(ch api.Channel, index interfaces.InterfaceIndex) {
+	fmt.Printf("Dumping IP addresses for interface index %d\n", index)
 
 	req := &ip.IPAddressDump{
-		SwIfIndex: 1,
+		SwIfIndex: index,
 	}
 	reqCtx := ch.SendMultiRequest(req)
 
@@ -198,13 +208,14 @@ func ipAddressDump(ch api.Channel) {
 	}
 
 	fmt.Println("OK")
+	fmt.Println()
 }
 
 // interfaceNotifications shows the usage of notification API. Note that for notifications,
 // you are supposed to create your own Go channel with your preferred buffer size. If the channel's
 // buffer is full, the notifications will not be delivered into it.
-func interfaceNotifications(ch api.Channel) {
-	fmt.Println("Subscribing to notificaiton events")
+func interfaceNotifications(ch api.Channel, index interfaces.InterfaceIndex) {
+	fmt.Printf("Subscribing to notificaiton events for interface index %d\n", index)
 
 	notifChan := make(chan api.Message, 100)
 
@@ -225,27 +236,31 @@ func interfaceNotifications(ch api.Channel) {
 		return
 	}
 
+	// receive notifications
+	go func() {
+		for notif := range notifChan {
+			fmt.Printf("incoming event: %+v\n", notif.(*interfaces.SwInterfaceEvent))
+		}
+	}()
+
 	// generate some events in VPP
 	err = ch.SendRequest(&interfaces.SwInterfaceSetFlags{
-		SwIfIndex: 1,
+		SwIfIndex: index,
+		Flags:     interface_types.IF_STATUS_API_FLAG_ADMIN_UP,
 	}).ReceiveReply(&interfaces.SwInterfaceSetFlagsReply{})
 	if err != nil {
 		logError(err, "setting interface flags")
 		return
 	}
 	err = ch.SendRequest(&interfaces.SwInterfaceSetFlags{
-		SwIfIndex: 1,
-		Flags:     interface_types.IF_STATUS_API_FLAG_ADMIN_UP,
+		SwIfIndex: index,
+		Flags:     0,
 	}).ReceiveReply(&interfaces.SwInterfaceSetFlagsReply{})
 	if err != nil {
 		logError(err, "setting interface flags")
 		return
 	}
 
-	// receive one notification
-	notif := (<-notifChan).(*interfaces.SwInterfaceEvent)
-	fmt.Printf("incoming event: %+v\n", notif)
-
 	// disable interface events in VPP
 	err = ch.SendRequest(&interfaces.WantInterfaceEvents{
 		PID:           uint32(os.Getpid()),
@@ -263,6 +278,7 @@ func interfaceNotifications(ch api.Channel) {
 		return
 	}
 
+	fmt.Println("OK")
 	fmt.Println()
 }
 
diff --git a/examples/union-example/union_example.go b/examples/union-example/union_example.go
index 92c3ec2..9993ee1 100644
--- a/examples/union-example/union_example.go
+++ b/examples/union-example/union_example.go
@@ -16,73 +16,82 @@
 package main
 
 import (
-	"bytes"
 	"fmt"
 	"log"
 	"net"
+	"reflect"
 
+	"git.fd.io/govpp.git/codec"
 	"git.fd.io/govpp.git/examples/binapi/ip"
 	"git.fd.io/govpp.git/examples/binapi/ip_types"
-
-	"github.com/lunixbochs/struc"
 )
 
+func init() {
+	log.SetFlags(0)
+}
+
 func main() {
+	constructExample()
+
 	encodingExample()
-	usageExample()
+
+	// convert IP from string form into Address type containing union
+	convertIP("10.10.1.1")
+	convertIP("ff80::1")
 }
 
-func encodingExample() {
-	// create union with IPv4 address
-	var unionIP4 ip.AddressUnion
-	unionIP4.SetIP4(ip.IP4Address{192, 168, 1, 10})
-
-	// use it in the Address type
-	addr := &ip.Address{
-		Af: ip_types.ADDRESS_IP4,
-		Un: ip_types.AddressUnionIP4(ip.IP4Address{192, 168, 1, 10}),
-	}
-	log.Printf("encoding union IPv4: %v", addr.Un.GetIP4())
+func constructExample() {
+	var union ip_types.AddressUnion
 
-	// encode the address with union
-	data := encode(addr)
-	// decode the address with union
-	addr2 := decode(data)
+	// create AddressUnion with AdressUnionXXX constructors
+	union = ip_types.AddressUnionIP4(ip.IP4Address{192, 168, 1, 10})
+	union = ip_types.AddressUnionIP6(ip.IP6Address{0xff, 0x02, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0x02})
 
-	log.Printf("decoded union IPv4: %v", addr2.Un.GetIP4())
+	// set AddressUnion with SetXXX methods
+	union.SetIP4(ip.IP4Address{192, 168, 1, 10})
+	union.SetIP6(ip.IP6Address{0xff, 0x02, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0x02})
 }
 
-func encode(addr *ip.Address) []byte {
-	log.Printf("encoding address: %#v", addr)
-	buf := new(bytes.Buffer)
-	if err := struc.Pack(buf, addr); err != nil {
-		panic(err)
+func encodingExample() {
+	var c codec.MsgCodec
+
+	// encode this message
+	var msg = ip.IPPuntRedirect{
+		Punt: ip.PuntRedirect{
+			Nh: ip_types.Address{
+				Af: ip_types.ADDRESS_IP4,
+				Un: ip_types.AddressUnionIP4(ip.IP4Address{192, 168, 1, 10}),
+			},
+		},
+		IsAdd: true,
 	}
-	return buf.Bytes()
-}
+	log.Printf("encoding message: %+v", msg)
 
-func decode(data []byte) *ip.Address {
-	addr := new(ip.Address)
-	buf := bytes.NewReader(data)
-	if err := struc.Unpack(buf, addr); err != nil {
-		panic(err)
+	b, err := c.EncodeMsg(&msg, 1)
+	if err != nil {
+		log.Fatal(err)
 	}
-	log.Printf("decoded address: %#v", addr)
-	return addr
-}
 
-func usageExample() {
-	var convAddr = func(ip string) {
-		addr, err := ipToAddress(ip)
-		if err != nil {
-			log.Printf("converting ip %q failed: %v", ip, err)
-		}
-		fmt.Printf("% 0X\n", addr)
+	// decode into this message
+	var msg2 ip.IPPuntRedirect
+	if err := c.DecodeMsg(b, &msg2); err != nil {
+		log.Fatal(err)
 	}
+	log.Printf("decoded message: %+v", msg2)
 
-	convAddr("10.10.10.10")
-	convAddr("::1")
-	convAddr("")
+	// compare the messages
+	if !reflect.DeepEqual(msg, msg2) {
+		log.Fatal("messages are not equal")
+	}
+}
+
+func convertIP(ip string) {
+	addr, err := ipToAddress(ip)
+	if err != nil {
+		log.Printf("error converting IP: %v", err)
+		return
+	}
+	fmt.Printf("converted IP %q to: %+v\n", ip, addr)
 }
 
 func ipToAddress(ipstr string) (addr ip.Address, err error) {
@@ -98,7 +107,7 @@ func ipToAddress(ipstr string) (addr ip.Address, err error) {
 	} else {
 		addr.Af = ip_types.ADDRESS_IP4
 		var ip4addr ip.IP4Address
-		copy(ip4addr[:], ip4)
+		copy(ip4addr[:], ip4.To4())
 		addr.Un.SetIP4(ip4addr)
 	}
 	return
diff --git a/go.mod b/go.mod
index cff5c18..09512f5 100644
--- a/go.mod
+++ b/go.mod
@@ -9,13 +9,13 @@ require (
 	github.com/golang/protobuf v1.3.2 // indirect
 	github.com/hpcloud/tail v1.0.0 // indirect
 	github.com/kr/pretty v0.1.0 // indirect
-	github.com/lunixbochs/struc v0.0.0-20190916212049-a5c72983bc42
+	github.com/lunixbochs/struc v0.0.0-20200521075829-a4cb8d33dbbe
 	github.com/onsi/ginkgo v1.8.0 // indirect
 	github.com/onsi/gomega v1.1.0
 	github.com/pkg/profile v1.2.1
-	github.com/sirupsen/logrus v1.0.0
+	github.com/sirupsen/logrus v1.6.0
 	github.com/stretchr/testify v1.3.0 // indirect
-	golang.org/x/sys v0.0.0-20170427041856-9ccfe848b9db // indirect
+	golang.org/x/sys v0.0.0-20200610111108-226ff32320da // indirect
 	gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127 // indirect
 	gopkg.in/fsnotify.v1 v1.4.7 // indirect
 	gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7 // indirect
diff --git a/go.sum b/go.sum
index 78f5650..188240b 100644
--- a/go.sum
+++ b/go.sum
@@ -2,6 +2,8 @@ github.com/bennyscetbun/jsongo v1.1.0 h1:ZDSks3aLP13jhY139lWaUqZaU8G0tELMohzumut
 github.com/bennyscetbun/jsongo v1.1.0/go.mod h1:suxbVmjBV8+A2BBAM5EYVh6Uj8j3rqJhzWf3hv7Ff8U=
 github.com/davecgh/go-spew v1.1.0 h1:ZDRjVQ15GmhC3fiQ8ni8+OwkZQO4DARzQgrnXU1Liz8=
 github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
+github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
+github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
 github.com/fsnotify/fsnotify v0.0.0-20170329110642-4da3e2cfbabc h1:fqUzyjP8DApxXq0dOZJE/NvqQkyjxiTy9ARNyRwBPEw=
 github.com/fsnotify/fsnotify v0.0.0-20170329110642-4da3e2cfbabc/go.mod h1:jwhsz4b93w/PPRr/qN1Yymfu8t87LnFCMoQvtojpjFo=
 github.com/ftrvxmtrx/fd v0.0.0-20150925145434-c6d800382fff h1:zk1wwii7uXmI0znwU+lqg+wFL9G5+vm5I+9rv2let60=
@@ -10,13 +12,15 @@ github.com/golang/protobuf v1.3.2 h1:6nsPYzhq5kReh6QImI3k5qWzO4PEbvbIW2cwSfR/6xs
 github.com/golang/protobuf v1.3.2/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
 github.com/hpcloud/tail v1.0.0 h1:nfCOvKYfkgYP8hkirhJocXT2+zOD8yUNjXaWfTlyFKI=
 github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU=
+github.com/konsorten/go-windows-terminal-sequences v1.0.3 h1:CE8S1cTafDpPvMhIxNJKvHsGVBgn1xWYf1NbHQhywc8=
+github.com/konsorten/go-windows-terminal-sequences v1.0.3/go.mod h1:T0+1ngSBFLxvqU3pZ+m/2kptfBszLMUkC4ZK/EgS/cQ=
 github.com/kr/pretty v0.1.0 h1:L/CwN0zerZDmRFUapSPitk6f+Q3+0za1rQkzVuMiMFI=
 github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo=
 github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ=
 github.com/kr/text v0.1.0 h1:45sCR5RtlFHMR4UwH9sdQ5TC8v0qDQCHnXt+kaKSTVE=
 github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
-github.com/lunixbochs/struc v0.0.0-20190916212049-a5c72983bc42 h1:PzBD7QuxXSgSu61TKXxRwVGzWO5d9QZ0HxFFpndZMCg=
-github.com/lunixbochs/struc v0.0.0-20190916212049-a5c72983bc42/go.mod h1:vy1vK6wD6j7xX6O6hXe621WabdtNkou2h7uRtTfRMyg=
+github.com/lunixbochs/struc v0.0.0-20200521075829-a4cb8d33dbbe h1:ewr1srjRCmcQogPQ/NCx6XCk6LGVmsVCc9Y3vvPZj+Y=
+github.com/lunixbochs/struc v0.0.0-20200521075829-a4cb8d33dbbe/go.mod h1:vy1vK6wD6j7xX6O6hXe621WabdtNkou2h7uRtTfRMyg=
 github.com/onsi/ginkgo v1.8.0 h1:VkHVNpR4iVnU8XQR6DBm8BqYjN7CRzw+xKUbVVbbW9w=
 github.com/onsi/ginkgo v1.8.0/go.mod h1:lLunBs/Ym6LB5Z9jYTR76FiuTmxDTDusOGeTQH+WWjE=
 github.com/onsi/gomega v1.1.0 h1:e3YP4dN/HYPpGh29X1ZkcxcEICsOls9huyVCRBaxjq8=
@@ -25,13 +29,16 @@ github.com/pkg/profile v1.2.1 h1:F++O52m40owAmADcojzM+9gyjmMOY/T4oYJkgFDH8RE=
 github.com/pkg/profile v1.2.1/go.mod h1:hJw3o1OdXxsrSjjVksARp5W95eeEaEfptyVZyv6JUPA=
 github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
-github.com/sirupsen/logrus v1.0.0 h1:XM8X4m/9ACaclZMs946FQNEZBZafvToJLTR4007drwo=
-github.com/sirupsen/logrus v1.0.0/go.mod h1:pMByvHTf9Beacp5x1UXfOR9xyW/9antXMhjMPG0dEzc=
+github.com/sirupsen/logrus v1.6.0 h1:UBcNElsrwanuuMsnGSlYmtmgbb23qDR5dG+6X6Oo89I=
+github.com/sirupsen/logrus v1.6.0/go.mod h1:7uNnSEd1DgxDLC74fIahvMZmmYsHGZGEOFrfsX/uA88=
 github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
+github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
 github.com/stretchr/testify v1.3.0 h1:TivCn/peBQ7UY8ooIcPgZFpTNSz0Q2U6UrFlUfqbe0Q=
 github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
-golang.org/x/sys v0.0.0-20170427041856-9ccfe848b9db h1:znurcNjtwV7XblDOBERYCP1TUjpwbp8bi3Szx8gbNBE=
-golang.org/x/sys v0.0.0-20170427041856-9ccfe848b9db/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
+golang.org/x/sys v0.0.0-20190422165155-953cdadca894 h1:Cz4ceDQGXuKRnVBDTS23GTn/pU5OE2C0WrNTOYK1Uuc=
+golang.org/x/sys v0.0.0-20190422165155-953cdadca894/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20200610111108-226ff32320da h1:bGb80FudwxpeucJUjPYJXuJ8Hk91vNtfvrymzwiei38=
+golang.org/x/sys v0.0.0-20200610111108-226ff32320da/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
 gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127 h1:qIbj1fsPNlZgppZ+VLlY7N33q108Sa+fhmuc+sWQYwY=
 gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
 gopkg.in/fsnotify.v1 v1.4.7 h1:xOHLXZwVvI9hhs+cLKq5+I5onOuwQLhQwiu63xxlHs4=
diff --git a/version/version.go b/version/version.go
index eb8063a..8bde72c 100644
--- a/version/version.go
+++ b/version/version.go
@@ -21,14 +21,17 @@ import (
 	"time"
 )
 
+// Following variables should normally be updated via `-ldflags "-X ..."`.
+// However, the version string is hard-coded to ensure it is always included
+// even with bare go build/install.
 var (
-	name        = "govpp"
-	version     = "v0.3.5"
-	commitHash  = "unknown"
-	buildBranch = "HEAD"
-	buildStamp  = ""
-	buildUser   = ""
-	buildHost   = ""
+	name       = "govpp"
+	version    = "v0.4.0-dev"
+	commit     = "unknown"
+	branch     = "HEAD"
+	buildStamp = ""
+	buildUser  = ""
+	buildHost  = ""
 
 	buildDate time.Time
 )
@@ -41,6 +44,10 @@ func init() {
 	buildDate = time.Unix(buildstampInt64, 0)
 }
 
+func Version() string {
+	return version
+}
+
 func Info() string {
 	return fmt.Sprintf(`%s %s`, name, version)
 }
@@ -54,7 +61,7 @@ func Verbose() string {
   Build date:	%s
   Go runtime:	%s (%s/%s)`,
 		name,
-		version, buildBranch, commitHash,
+		version, branch, commit,
 		buildUser, buildHost, buildDate.Format(time.UnixDate),
 		runtime.Version(), runtime.GOOS, runtime.GOARCH,
 	)
-- 
cgit 1.2.3-korg