[VOL-2231] Cleaning the packet-in/out logs and dumping packets in HEX
Change-Id: I22fe6b8b39fb683cea89bb93b1baa2ed2a664398
diff --git a/go.mod b/go.mod
index 91f0efe..b146eae 100644
--- a/go.mod
+++ b/go.mod
@@ -9,6 +9,7 @@
github.com/google/uuid v1.1.1
github.com/gyuho/goraph v0.0.0-20160328020532-d460590d53a9
github.com/opencord/voltha-lib-go/v2 v2.2.13
+ github.com/mdlayher/ethernet v0.0.0-20190606142754-0394541c37b7 // indirect
github.com/opencord/voltha-protos/v2 v2.0.1
github.com/phayes/freeport v0.0.0-20180830031419-95f893ade6f2
github.com/stretchr/testify v1.4.0
diff --git a/go.sum b/go.sum
index 130c6bc..9285efd 100644
--- a/go.sum
+++ b/go.sum
@@ -83,6 +83,7 @@
github.com/google/btree v1.0.0 h1:0udJVsspx3VBr5FwtLhQQtuAsVc79tTq0ocGIPAU6qo=
github.com/google/btree v1.0.0/go.mod h1:lNA+9X1NB3Zf8V7Ke586lFgjr2dZNuvo3lPJSGZ5JPQ=
github.com/google/go-cmp v0.2.0/go.mod h1:oXzfMopK8JAjlY9xF4vHSVASa0yLyX7SntLO5aqRK0M=
+github.com/google/go-cmp v0.3.0/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU=
github.com/google/go-cmp v0.3.1 h1:Xye71clBPdm5HgqGwUkwhbynsUJZhDbS20FvLhQ2izg=
github.com/google/go-cmp v0.3.1/go.mod h1:8QqcDgzrUqlUb/G2PQTWiueGozuR1884gddMywk6iLU=
github.com/google/gofuzz v1.0.0/go.mod h1:dBl0BpW6vV/+mYPU4Po3pmUjxk6FQPldtuIdl/M65Eg=
@@ -167,6 +168,9 @@
github.com/mattn/go-runewidth v0.0.2/go.mod h1:LwmH8dsx7+W8Uxz3IHJYH5QSwggIsqBzpuz5H//U1FU=
github.com/matttproud/golang_protobuf_extensions v1.0.1 h1:4hp9jkHxhMHkqkrB3Ix0jegS5sx/RkqARlsWZ6pIwiU=
github.com/matttproud/golang_protobuf_extensions v1.0.1/go.mod h1:D8He9yQNgCq6Z5Ld7szi9bcBfOoFv/3dc6xSMkL2PC0=
+github.com/mdlayher/ethernet v0.0.0-20190606142754-0394541c37b7 h1:lez6TS6aAau+8wXUP3G9I3TGlmPFEq2CTxBaRqY6AGE=
+github.com/mdlayher/ethernet v0.0.0-20190606142754-0394541c37b7/go.mod h1:U6ZQobyTjI/tJyq2HG+i/dfSoFUt8/aZCM+GKtmFk/Y=
+github.com/mdlayher/raw v0.0.0-20190606142536-fef19f00fc18/go.mod h1:7EpbotpCmVZcu+KCX4g9WaRNuu11uyhiW7+Le1dKawg=
github.com/miekg/dns v1.0.14 h1:9jZdLNd/P4+SfEJ0TNyxYpsK8N4GtfylBLqtbYN1sbA=
github.com/miekg/dns v1.0.14/go.mod h1:W1PPwlIAgtquWBMBEV9nkV9Cazfe8ScdGz/Lj7v3Nrg=
github.com/mitchellh/cli v1.0.0/go.mod h1:hNIlj7HEI86fIcpObd7a0FcrxTWetlwJDGcceTlRvqc=
@@ -194,6 +198,12 @@
github.com/onsi/gomega v1.4.2/go.mod h1:ex+gbHU/CVuBBDIJjb2X0qEXbFg53c61hWP/1CpauHY=
github.com/opencord/voltha-lib-go/v2 v2.2.13 h1:8TxMjhqOL2vcDxO5uIaAd6Lj2Ahq/gAFiNNoUkM90cQ=
github.com/opencord/voltha-lib-go/v2 v2.2.13/go.mod h1:g8WH4WTOJ0f40ZoqYFR4nyOLIAC84dOKDXsbT1ZErY4=
+github.com/opencord/voltha-lib-go/v2 v2.2.12 h1:QymMvOZwrnW3caPmeUycNqMGZceNC8x3AC5exF5IO4E=
+github.com/opencord/voltha-lib-go/v2 v2.2.12/go.mod h1:Hql0xWiBFqYM6WpE5G+w9//NdaIoR9mVzcvVYDxEnZY=
+github.com/opencord/voltha-openolt-adapter v2.2.0+incompatible h1:l6hLGWS4dUgrsxrDeR94rBPLQzTWnUKeYAyyy9zm4BI=
+github.com/opencord/voltha-openolt-adapter v2.2.0+incompatible/go.mod h1:iQvDqrEvGeq6WQfNTJt7ekhCSo0tHa1qWxZhIaNTb9Q=
+github.com/opencord/voltha-protos v1.0.3 h1:9v+R/QGF1xK+HKTqFM0IqCABoGCAxC8iKH4VzNBJDto=
+github.com/opencord/voltha-protos v1.0.3/go.mod h1:myfFIkJdA+rCXmKdLImhh79MfabN4ZOKQ4grk32DnPQ=
github.com/opencord/voltha-protos/v2 v2.0.1 h1:vcE0XxNVeu0SED0bW2lf2w24k/QMFrFqMexuedIyTEg=
github.com/opencord/voltha-protos/v2 v2.0.1/go.mod h1:6kOcfYi1CadWowFxI2SH5wLfHrsRECZLZlD2MFK6WDI=
github.com/pascaldekloe/goe v0.0.0-20180627143212-57f6aae5913c/go.mod h1:lzWF7FIEvWOWxwDKqyGYQf6ZUaNfKdP144TG7ZOy1lc=
@@ -286,6 +296,8 @@
golang.org/x/net v0.0.0-20190213061140-3a22650c66bd/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4=
golang.org/x/net v0.0.0-20190311183353-d8887717615a/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
+golang.org/x/net v0.0.0-20190419010253-1f3472d942ba/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
+golang.org/x/net v0.0.0-20190603091049-60506f45cf65/go.mod h1:HSz+uSET+XFnRR8LxR5pz3Of3rY3CfYBVs4xY44aLks=
golang.org/x/net v0.0.0-20190813141303-74dc4d7220e7/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s=
golang.org/x/net v0.0.0-20190930134127-c5a3c61f89f3 h1:6KET3Sqa7fkVfD63QnAM81ZeYg5n4HwApOJkufONnHA=
golang.org/x/net v0.0.0-20190930134127-c5a3c61f89f3/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s=
@@ -305,6 +317,8 @@
golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
golang.org/x/sys v0.0.0-20190403152447-81d4e9dc473e/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20190418153312-f0ce4c0180be/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
+golang.org/x/sys v0.0.0-20190606122018-79a91cf218c4/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20190826190057-c7b8b68b1456/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20191001151750-bb3f8db39f24 h1:R8bzl0244nw47n1xKs1MUMAaTNgjavKcN/aX2Ss3+Fo=
golang.org/x/sys v0.0.0-20191001151750-bb3f8db39f24/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
diff --git a/python/ofagent/grpc_client.py b/python/ofagent/grpc_client.py
index e4b260e..c8b2580 100755
--- a/python/ofagent/grpc_client.py
+++ b/python/ofagent/grpc_client.py
@@ -33,6 +33,7 @@
FlowGroupTableUpdate, PacketOut
from voltha_protos.logical_device_pb2 import LogicalPortId
from google.protobuf import empty_pb2
+from binascii import hexlify
log = get_logger()
@@ -126,7 +127,8 @@
packet_in)
log.debug('enqueued-packet-in',
packet_in=packet_in,
- queue_len=len(self.packet_in_queue.pending))
+ queue_len=len(self.packet_in_queue.pending),
+ packet=hexlify(packet_in.packet_in.data))
except _Rendezvous, e:
log.error('grpc-exception', status=e.code())
if e.code() == StatusCode.UNAVAILABLE:
@@ -172,13 +174,13 @@
packet_in = yield self.packet_in_queue.get()
device_id = packet_in.id
ofp_packet_in = packet_in.packet_in
- log.debug('grpc client to send packet-in')
+ log.debug('grpc client to send packet-in', packet=hexlify(packet_in.packet_in.data))
self.connection_manager.forward_packet_in(device_id, ofp_packet_in)
if self.stopped:
break
def send_packet_out(self, device_id, packet_out):
- log.debug('grpc client to send packet-out')
+ log.debug('grpc client to send packet-out', packet=hexlify(packet_out.data))
packet_out = PacketOut(id=device_id, packet_out=packet_out)
self.packet_out_queue.put(packet_out)
diff --git a/python/ofagent/of_protocol_handler.py b/python/ofagent/of_protocol_handler.py
index e90ca5b..a4b3f70 100755
--- a/python/ofagent/of_protocol_handler.py
+++ b/python/ofagent/of_protocol_handler.py
@@ -18,6 +18,7 @@
import loxi.of13 as ofp
from converter import to_loxi, pb2dict, to_grpc
+from binascii import hexlify
log = structlog.get_logger()
@@ -348,7 +349,7 @@
def forward_packet_in(self, ofp_packet_in):
if self.role == ofp.OFPCR_ROLE_MASTER or self.role == ofp.OFPCR_ROLE_EQUAL:
- log.info('sending-packet-in', ofp_packet_in=ofp_packet_in)
+ log.info('sending-packet-in', ofp_packet_in=ofp_packet_in, packet=hexlify(ofp_packet_in.data))
self.cxn.send(to_loxi(ofp_packet_in))
def forward_port_status(self, ofp_port_status):
diff --git a/rw_core/core/device_agent.go b/rw_core/core/device_agent.go
index 3d356ec..97c0b2d 100755
--- a/rw_core/core/device_agent.go
+++ b/rw_core/core/device_agent.go
@@ -17,6 +17,7 @@
import (
"context"
+ "encoding/hex"
"fmt"
"reflect"
"sync"
@@ -1005,7 +1006,11 @@
func (agent *DeviceAgent) packetOut(outPort uint32, packet *ofp.OfpPacketOut) error {
// Send packet to adapter
if err := agent.adapterProxy.packetOut(agent.deviceType, agent.deviceId, outPort, packet); err != nil {
- log.Debugw("packet-out-error", log.Fields{"id": agent.lastData.Id, "error": err})
+ log.Debugw("packet-out-error", log.Fields{
+ "id": agent.lastData.Id,
+ "error": err,
+ "packet": hex.EncodeToString(packet.Data),
+ })
return err
}
return nil
diff --git a/rw_core/core/grpc_nbi_api_handler.go b/rw_core/core/grpc_nbi_api_handler.go
index 87f42c6..0aa74f5 100755
--- a/rw_core/core/grpc_nbi_api_handler.go
+++ b/rw_core/core/grpc_nbi_api_handler.go
@@ -17,6 +17,7 @@
import (
"context"
+ "encoding/hex"
"encoding/json"
"errors"
"github.com/golang/protobuf/ptypes/empty"
@@ -959,7 +960,9 @@
for {
select {
case packet := <-handler.packetInQueue:
- log.Debugw("sending-packet-in", log.Fields{"packet": packet})
+ log.Debugw("sending-packet-in", log.Fields{
+ "packet": hex.EncodeToString(packet.PacketIn.Data),
+ })
if err := packetsIn.Send(&packet); err != nil {
log.Errorw("failed-to-send-packet", log.Fields{"error": err})
// save the last failed packet in
diff --git a/rw_core/core/logical_device_agent.go b/rw_core/core/logical_device_agent.go
index 1bdfc1c..e04b4d6 100644
--- a/rw_core/core/logical_device_agent.go
+++ b/rw_core/core/logical_device_agent.go
@@ -17,6 +17,7 @@
import (
"context"
+ "encoding/hex"
"errors"
"fmt"
"github.com/gogo/protobuf/proto"
@@ -1882,7 +1883,10 @@
}
func (agent *LogicalDeviceAgent) packetOut(packet *ofp.OfpPacketOut) {
- log.Debugw("packet-out", log.Fields{"packet": packet.GetInPort()})
+ log.Debugw("packet-out", log.Fields{
+ "packet": hex.EncodeToString(packet.Data),
+ "inPort": packet.GetInPort(),
+ })
outPort := fu.GetPacketOutPort(packet)
//frame := packet.GetData()
//TODO: Use a channel between the logical agent and the device agent
@@ -1892,10 +1896,14 @@
}
func (agent *LogicalDeviceAgent) packetIn(port uint32, transactionId string, packet []byte) {
- log.Debugw("packet-in", log.Fields{"port": port, "packet": packet, "transactionId": transactionId})
+ log.Debugw("packet-in", log.Fields{
+ "port": port,
+ "packet": hex.EncodeToString(packet),
+ "transactionId": transactionId,
+ })
packetIn := fu.MkPacketIn(port, packet)
agent.ldeviceMgr.grpcNbiHdlr.sendPacketIn(agent.logicalDeviceId, transactionId, packetIn)
- log.Debugw("sending-packet-in", log.Fields{"packet-in": packetIn})
+ log.Debugw("sending-packet-in", log.Fields{"packet": hex.EncodeToString(packetIn.Data)})
}
func (agent *LogicalDeviceAgent) addLogicalPortToMap(portNo uint32, nniPort bool) {