Adding trace logging to emitted and received packets

Change-Id: Id23be0d7fb70258c5de9900f099575404329746a
diff --git a/src/main/java/org/opencord/aaa/AaaManager.java b/src/main/java/org/opencord/aaa/AaaManager.java
index 120f14f..b527d91 100755
--- a/src/main/java/org/opencord/aaa/AaaManager.java
+++ b/src/main/java/org/opencord/aaa/AaaManager.java
@@ -15,6 +15,13 @@
  */
 package org.opencord.aaa;
 
+import static org.onosproject.net.config.basics.SubjectFactories.APP_SUBJECT_FACTORY;
+import static org.slf4j.LoggerFactory.getLogger;
+
+import java.net.InetAddress;
+import java.nio.ByteBuffer;
+import java.util.Map;
+
 import org.apache.commons.lang3.builder.ToStringBuilder;
 import org.apache.felix.scr.annotations.Component;
 import org.apache.felix.scr.annotations.Deactivate;
@@ -55,13 +62,6 @@
 import org.osgi.service.component.annotations.Activate;
 import org.slf4j.Logger;
 
-import java.net.InetAddress;
-import java.nio.ByteBuffer;
-import java.util.Map;
-
-import static org.onosproject.net.config.basics.SubjectFactories.APP_SUBJECT_FACTORY;
-import static org.slf4j.LoggerFactory.getLogger;
-
 /**
  * AAA application for ONOS.
  */
@@ -269,9 +269,13 @@
      */
     public void handleRadiusPacket(RADIUS radiusPacket)
             throws StateMachineException, DeserializationException {
+        if (log.isTraceEnabled()) {
+            log.trace("Received RADIUS packet {}", radiusPacket);
+        }
         StateMachine stateMachine = StateMachine.lookupStateMachineById(radiusPacket.getIdentifier());
         if (stateMachine == null) {
-            log.error("Invalid session identifier {}, exiting...", radiusPacket.getIdentifier());
+            log.error("Invalid packet identifier {}, could not find corresponding "
+                    + "state machine ... exiting", radiusPacket.getIdentifier());
             return;
         }
 
@@ -354,6 +358,11 @@
         TrafficTreatment treatment = DefaultTrafficTreatment.builder().setOutput(connectPoint.port()).build();
         OutboundPacket packet = new DefaultOutboundPacket(connectPoint.deviceId(),
                                                           treatment, ByteBuffer.wrap(ethernetPkt.serialize()));
+        if (log.isTraceEnabled()) {
+            EAPOL eap = ((EAPOL) ethernetPkt.getPayload());
+            log.trace("Sending eapol payload {} enclosed in {} to supplicant at {}",
+                      eap, ethernetPkt, connectPoint);
+        }
         packetService.emit(packet);
     }
 
@@ -433,12 +442,22 @@
             DeviceId deviceId = inPacket.receivedFrom().deviceId();
             PortNumber portNumber = inPacket.receivedFrom().port();
             String sessionId = deviceId.toString() + portNumber.toString();
-            StateMachine stateMachine = StateMachine.lookupStateMachineBySessionId(sessionId);
-            if (stateMachine == null) {
-                stateMachine = new StateMachine(sessionId);
+            EAPOL eapol = (EAPOL) ethPkt.getPayload();
+            if (log.isTraceEnabled()) {
+                log.trace("Received EAPOL packet {} in enclosing packet {} from "
+                        + "dev/port: {}/{}", eapol, ethPkt, deviceId,
+                          portNumber);
             }
 
-            EAPOL eapol = (EAPOL) ethPkt.getPayload();
+            StateMachine stateMachine = StateMachine.lookupStateMachineBySessionId(sessionId);
+            if (stateMachine == null) {
+                log.debug("Creating new state machine for sessionId: {} for "
+                                + "dev/port: {}/{}", sessionId, deviceId, portNumber);
+                stateMachine = new StateMachine(sessionId);
+            } else {
+                log.debug("Using existing state-machine for sessionId: {}", sessionId);
+            }
+
 
             switch (eapol.getEapolType()) {
                 case EAPOL.EAPOL_START: