Simplify packet i/o trace logging for P4Runtime

Change-Id: I3b45597fc68fefb485f860597bcc65d7c03e523a

Author: ccascone

drivers/p4runtime/src/main/java/org/onosproject/drivers/p4runtime/P4RuntimePacketProgrammable.java

@@ -16,14 +16,17 @@
 
 package org.onosproject.drivers.p4runtime;
 
+import org.onlab.packet.EthType;
+import org.onosproject.net.flow.instructions.Instructions;
 import org.onosproject.net.packet.OutboundPacket;
 import org.onosproject.net.packet.PacketProgrammable;
 import org.onosproject.net.pi.model.PiPipelineInterpreter;
-import org.onosproject.net.pi.runtime.PiPacketOperation;
 
-import java.util.Collection;
+import java.nio.ByteBuffer;
+import java.util.stream.Collectors;
 
 import static org.onosproject.drivers.p4runtime.P4RuntimeDriverUtils.getInterpreter;
+import static org.onosproject.net.flow.instructions.Instruction.Type.OUTPUT;
 
 /**
  * Implementation of PacketProgrammable behaviour for P4Runtime.
@@ -45,15 +48,36 @@ public void emit(OutboundPacket packet) {
             return;
         }
 
+        if (log.isTraceEnabled()) {
+            logPacketOut(packet);
+        }
+
         try {
-            Collection<PiPacketOperation> operations = interpreter.mapOutboundPacket(packet);
-            operations.forEach(piPacketOperation -> {
-                log.debug("Doing PiPacketOperation {}", piPacketOperation);
-                client.packetOut(p4DeviceId, piPacketOperation, pipeconf);
-            });
+            interpreter.mapOutboundPacket(packet).forEach(
+                    op -> client.packetOut(p4DeviceId, op, pipeconf));
         } catch (PiPipelineInterpreter.PiInterpreterException e) {
             log.error("Unable to translate outbound packet for {} with pipeconf {}: {}",
                       deviceId, pipeconf.id(), e.getMessage());
         }
     }
+
+    private void logPacketOut(OutboundPacket packet) {
+        final EthType.EtherType etherType = getEtherType(packet.data());
+        final String outPorts = packet.treatment().immediate().stream()
+                .filter(i -> i.type().equals(OUTPUT))
+                .map(i -> Long.toString(((Instructions.OutputInstruction) i).port().toLong()))
+                .collect(Collectors.joining(","));
+        final String desc = outPorts.isBlank()
+                ? "treatment=" + packet.treatment().toString()
+                : "egress_ports=" + outPorts;
+        log.trace("Sending PACKET-OUT >>> device={} {} eth_type={}",
+                  packet.sendThrough(), desc,
+                  etherType.ethType().toString());
+    }
+
+    private EthType.EtherType getEtherType(ByteBuffer data) {
+        final short shortEthType = data.getShort(12);
+        data.rewind();
+        return EthType.EtherType.lookup(shortEthType);
+    }
 }

providers/p4runtime/packet/src/main/java/org/onosproject/provider/p4runtime/packet/impl/P4RuntimePacketProvider.java

@@ -17,6 +17,7 @@
 package org.onosproject.provider.p4runtime.packet.impl;
 
 
+import org.onlab.packet.EthType;
 import org.onosproject.mastership.MastershipService;
 import org.onosproject.net.Device;
 import org.onosproject.net.DeviceId;
@@ -111,6 +112,12 @@ public void emit(OutboundPacket packet) {
         }
     }
 
+    private EthType.EtherType getEtherType(ByteBuffer data) {
+        final short shortEthType = data.getShort(12);
+        data.rewind();
+        return EthType.EtherType.lookup(shortEthType);
+    }
+
     /**
      * Internal packet context implementation.
      */
@@ -139,7 +146,6 @@ public void send() {
             }
 
             OutboundPacket outboundPacket = new DefaultOutboundPacket(deviceId, treatment, rawData);
-            log.debug("Processing outbound packet: {}", outboundPacket);
 
             emit(outboundPacket);
         }
@@ -155,7 +161,7 @@ public void event(P4RuntimeEvent event) {
             //Masterhip message is sent to everybody but picked up only by master.
             //FIXME we need the device ID into p4RuntimeEvnetSubject to check for mastsership
             if (!(event.subject() instanceof P4RuntimePacketIn) || event.type() != P4RuntimeEvent.Type.PACKET_IN) {
-                log.debug("Event type {}", event.type());
+                log.debug("Unrecognized event type {}, discarding", event.type());
                 // Not a packet-in event, ignore it.
                 return;
             }
@@ -183,13 +189,18 @@ public void event(P4RuntimeEvent event) {
                 return;
             }
 
+            if (log.isTraceEnabled()) {
+                final EthType.EtherType etherType = getEtherType(inPkt.unparsed());
+                log.trace("Received PACKET-IN <<< device={} ingress_port={} eth_type={}",
+                          inPkt.receivedFrom().deviceId(), inPkt.receivedFrom().port(),
+                          etherType.ethType().toString());
+            }
+
             if (inPkt == null) {
                 log.debug("Received null inbound packet. Ignoring.");
                 return;
             }
 
-            log.debug("Processing inbound packet: {}", inPkt.toString());
-
             OutboundPacket outPkt = new DefaultOutboundPacket(eventSubject.deviceId(), null,
                     operation.data().asReadOnlyBuffer());
             PacketContext pktCtx = new P4RuntimePacketContext(System.currentTimeMillis(), inPkt, outPkt, false);