dp log added

lib/gtp/gtp_message.c

@@ -26,10 +26,11 @@
 /*******************************************************************************
  * This file had been created by gtp_tlv.py script v0.1.0
  * Please do not modify this file but regenerate it via script.
- * Created on: 2017-09-14 13:57:05.211841 by acetcom
+ * Created on: 2018-01-23 16:32:53.073144 by acetcom
  * from 29274-d80.docx
  ******************************************************************************/
 
+#define TRACE_MODULE _gtp_message
 #include "core_debug.h"
 #include "gtp_message.h"
 
@@ -2778,6 +2779,9 @@ status_t gtp_parse_msg(gtp_message_t *gtp_message, pkbuf_t *pkbuf)
     d_assert(pkbuf, return CORE_ERROR, "Null param");
     d_assert(pkbuf->payload, return CORE_ERROR, "Null param");
 
+    d_trace(50, "[GTPv2] RECV : ");
+    d_trace_hex(50, pkbuf->payload, pkbuf->len);
+
     h = pkbuf->payload;
     d_assert(h, return CORE_ERROR, "Null param");
     
@@ -3052,6 +3056,12 @@ status_t gtp_build_msg(pkbuf_t **pkbuf, gtp_message_t *gtp_message)
             break;
     }
 
+    if ((*pkbuf) && (*pkbuf)->payload)
+    {
+        d_trace(50, "[GTPv2] SEND : ");
+        d_trace_hex(50, (*pkbuf)->payload, (*pkbuf)->len);
+    }
+
     return rv;
 }
 

lib/gtp/gtp_message.h

@@ -26,7 +26,7 @@
 /*******************************************************************************
  * This file had been created by gtp_tlv.py script v0.1.0
  * Please do not modify this file but regenerate it via script.
- * Created on: 2017-09-14 13:57:05.194620 by acetcom
+ * Created on: 2018-01-23 16:32:53.055846 by acetcom
  * from 29274-d80.docx
  ******************************************************************************/
 

lib/gtp/gtp_path.c

@@ -237,9 +237,6 @@ status_t gtp_send(gtp_node_t *gnode, pkbuf_t *pkbuf)
     d_assert(addr, return CORE_ERROR,);
 
     sent = core_send(sock, pkbuf->payload, pkbuf->len, 0);
-    d_trace(50, "Sent %d->%d bytes to [%s:%d]\n", pkbuf->len, sent, 
-            CORE_ADDR(addr, buf), CORE_PORT(addr));
-    d_trace_hex(50, pkbuf->payload, pkbuf->len);
     if (sent < 0 || sent != pkbuf->len)
     {
         d_error("core_send [%s]:%d failed(%d:%s)",

lib/gtp/support/gtp_tlv.py

@@ -546,7 +546,8 @@ f.close()
 
 f = open(outdir + 'gtp_message.c', 'w')
 output_header_to_file(f)
-f.write("""#include "core_debug.h"
+f.write("""#define TRACE_MODULE _gtp_message
+#include "core_debug.h"
 #include "gtp_message.h"
 
 """)
@@ -621,6 +622,9 @@ f.write("""status_t gtp_parse_msg(gtp_message_t *gtp_message, pkbuf_t *pkbuf)
     d_assert(pkbuf, return CORE_ERROR, "Null param");
     d_assert(pkbuf->payload, return CORE_ERROR, "Null param");
 
+    d_trace(50, "[GTPv2] RECV : ");
+    d_trace_hex(50, pkbuf->payload, pkbuf->len);
+
     h = pkbuf->payload;
     d_assert(h, return CORE_ERROR, "Null param");
     
@@ -679,6 +683,12 @@ f.write("""        default:
             break;
     }
 
+    if ((*pkbuf) && (*pkbuf)->payload)
+    {
+        d_trace(50, "[GTPv2] SEND : ");
+        d_trace_hex(50, (*pkbuf)->payload, (*pkbuf)->len);
+    }
+
     return rv;
 }
 """)

src/mme/mme_context.c

@@ -1533,16 +1533,20 @@ status_t mme_context_setup_trace_module()
     {
         extern int _mme_s11_handler;
         d_trace_level(&_mme_s11_handler, gtpv2);
-        extern int _gtp_node;
-        d_trace_level(&_gtp_node, gtpv2);
-        extern int _gtp_path;
-        d_trace_level(&_gtp_path, gtpv2);
         extern int _mme_gtp_path;
         d_trace_level(&_mme_gtp_path, gtpv2);
-        extern int _tlv_msg;
+
-        d_trace_level(&_tlv_msg, gtpv2);
+        extern int _gtp_node;
+        d_trace_level(&_gtp_node, gtpv2);
+        extern int _gtp_message;
+        d_trace_level(&_gtp_message, gtpv2);
+        extern int _gtp_path;
+        d_trace_level(&_gtp_path, gtpv2);
         extern int _gtp_xact;
         d_trace_level(&_gtp_xact, gtpv2);
+
+        extern int _tlv_msg;
+        d_trace_level(&_tlv_msg, gtpv2);
     }
 
     return CORE_OK;

src/mme/mme_gtp_path.c

@@ -27,7 +27,7 @@ static int _gtpv2_c_recv_cb(sock_id sock, void *data)
         return -1;
     }
 
-    d_trace(50, "[GTPv2] Receive : ");
+    d_trace(50, "[GTPv2] RECV : ");
     d_trace_hex(50, pkbuf->payload, pkbuf->len);
 
     event_set(&e, MME_EVT_S11_MESSAGE);

src/mme/s1ap_sctp.c

@@ -53,7 +53,7 @@ status_t s1ap_send(sock_id sock, pkbuf_t *pkbuf, c_sockaddr_t *addr)
 
     sent = core_sctp_sendmsg(sock, pkbuf->payload, pkbuf->len,
             addr, SCTP_S1AP_PPID, 0);
-    d_trace(50, "[S1AP] Sent %d bytes : ", sent);
+    d_trace(50, "[S1AP] SEND[%d] : ", sent);
     d_trace_hex(50, pkbuf->payload, pkbuf->len);
     if (sent < 0 || sent != pkbuf->len)
     {
@@ -186,7 +186,7 @@ int s1ap_recv_handler(sock_id sock, void *data)
 
     pkbuf->len = size;
 
-    d_trace(50, "[S1AP] Receive : ");
+    d_trace(50, "[S1AP] RECV : ");
     d_trace_hex(50, pkbuf->payload, pkbuf->len);
 
     addr = core_calloc(1, sizeof(c_sockaddr_t));

src/mme/s1ap_usrsctp.c

@@ -174,7 +174,7 @@ status_t s1ap_send(sock_id id, pkbuf_t *pkbuf, c_sockaddr_t *addr)
             (void *)&sndinfo, (socklen_t)sizeof(struct sctp_sndinfo),
             SCTP_SENDV_SNDINFO, 0);
 
-    d_trace(50, "[S1AP] Sent %d bytes : ", sent);
+    d_trace(50, "[S1AP] SEND[%d] : ", sent);
     d_trace_hex(50, pkbuf->payload, pkbuf->len);
     if (sent < 0 || sent != pkbuf->len)
     {
@@ -437,6 +437,9 @@ static int s1ap_usrsctp_recv_handler(struct socket *sock,
             pkbuf->len = datalen;
             memcpy(pkbuf->payload, data, pkbuf->len);
 
+            d_trace(50, "[S1AP] RECV : ");
+            d_trace_hex(50, pkbuf->payload, pkbuf->len);
+
             event_set(&e, MME_EVT_S1AP_MESSAGE);
             event_set_param1(&e, (c_uintptr_t)sock);
             event_set_param2(&e, (c_uintptr_t)addr);

src/pgw/pgw_context.c

@@ -892,20 +892,24 @@ status_t pgw_context_setup_trace_module()
         d_trace_level(&_pgw_s5c_build, gtpv2);
         extern int _pgw_s5c_handler;
         d_trace_level(&_pgw_s5c_handler, gtpv2);
+
         extern int _gtp_node;
         d_trace_level(&_gtp_node, gtpv2);
+        extern int _gtp_message;
+        d_trace_level(&_gtp_message, gtpv2);
         extern int _gtp_path;
         d_trace_level(&_gtp_path, gtpv2);
-        extern int _pgw_gtp_path;
-        d_trace_level(&_pgw_gtp_path, gtpv2);
-        extern int _tlv_msg;
-        d_trace_level(&_tlv_msg, gtpv2);
         extern int _gtp_xact;
         d_trace_level(&_gtp_xact, gtpv2);
+
+        extern int _tlv_msg;
+        d_trace_level(&_tlv_msg, gtpv2);
     }
 
     if (gtp)
     {
+        extern int _pgw_gtp_path;
+        d_trace_level(&_pgw_gtp_path, gtpv2);
         extern int _pgw_ipfw;
         d_trace_level(&_pgw_ipfw, gtp);
     }

src/pgw/pgw_gtp_path.c

@@ -39,7 +39,7 @@ static int _gtpv1_tun_recv_cb(sock_id sock, void *data)
 
     recvbuf->len = n;
 
-    d_trace(50, "PDU received from TunTap\n");
+    d_trace(50, "[TUN] RECV : ");
     d_trace_hex(50, recvbuf->payload, recvbuf->len);
 
     /* Find the bearer by packet filter */
@@ -81,9 +81,6 @@ static int _gtpv2_c_recv_cb(sock_id sock, void *data)
         return -1;
     }
 
-    d_trace(10, "S5-C PDU received from PGW\n");
-    d_trace_hex(10, pkbuf->payload, pkbuf->len);
-
     event_set(&e, PGW_EVT_S5C_MESSAGE);
     event_set_param1(&e, (c_uintptr_t)pkbuf);
     rv = pgw_event_send(&e);
@@ -123,11 +120,10 @@ static int _gtpv1_u_recv_cb(sock_id sock, void *data)
     }
 
     d_assert(pkbuf, return 0,);
-    d_trace(50, "S5-U PDU received from SGW\n");
+    d_assert(pkbuf->payload, goto cleanup,);
+    d_trace(50, "[PGW] RECV : ");
     d_trace_hex(50, pkbuf->payload, pkbuf->len);
 
-
-    d_assert(pkbuf->payload, goto cleanup,);
     gtp_h = pkbuf->payload;
     if (gtp_h->flags & GTPU_FLAGS_S) size += 4;
     teid = ntohl(gtp_h->teid);
@@ -383,8 +379,9 @@ static status_t pgw_gtp_send_to_bearer(pgw_bearer_t *bearer, pkbuf_t *sendbuf)
     gtp_h->teid = htonl(bearer->sgw_s5u_teid);
 
     /* Send to SGW */
-    d_trace(50, "Send S5U PDU (teid = 0x%x) to SGW\n",
+    d_trace(50, "[PGW] SEND : ");
-            bearer->sgw_s5u_teid);
+    d_trace_hex(50, sendbuf->payload, sendbuf->len);
+
     rv =  gtp_send(bearer->gnode, sendbuf);
 
     return rv;

src/sgw/sgw_context.c

@@ -480,20 +480,24 @@ status_t sgw_context_setup_trace_module()
         d_trace_level(&_sgw_s11_handler, gtpv2);
         extern int _sgw_s11_handler;
         d_trace_level(&_sgw_s11_handler, gtpv2);
+
         extern int _gtp_node;
         d_trace_level(&_gtp_node, gtpv2);
+        extern int _gtp_message;
+        d_trace_level(&_gtp_message, gtpv2);
         extern int _gtp_path;
         d_trace_level(&_gtp_path, gtpv2);
-        extern int _sgw_path;
-        d_trace_level(&_sgw_path, gtpv2);
-        extern int _tlv_msg;
-        d_trace_level(&_tlv_msg, gtpv2);
         extern int _gtp_xact;
         d_trace_level(&_gtp_xact, gtpv2);
+
+        extern int _tlv_msg;
+        d_trace_level(&_tlv_msg, gtpv2);
     }
 
     if (gtp)
     {
+        extern int _sgw_gtp_path;
+        d_trace_level(&_sgw_gtp_path, gtp);
     }
 
     return CORE_OK;

src/sgw/sgw_gtp_path.c

@@ -1,4 +1,4 @@
-#define TRACE_MODULE _sgw_path
+#define TRACE_MODULE _sgw_gtp_path
 #include "core_debug.h"
 #include "core_pkbuf.h"
 
@@ -37,18 +37,14 @@ static int _gtpv2_c_recv_cb(sock_id sock, void *data)
 
     if (SGW_S5C_TEID(teid))
     {
-        d_trace(50, "[GTPv2-S5C] Receive : ");
         event_set(&e, SGW_EVT_S5C_MESSAGE);
     }
     else
     {
-        d_trace(50, "[GTPv2-S11] Receive : ");
         event_set(&e, SGW_EVT_S11_MESSAGE);
     }
     event_set_param1(&e, (c_uintptr_t)pkbuf);
 
-    d_trace_hex(50, pkbuf->payload, pkbuf->len);
-
     rv = sgw_event_send(&e);
     if (rv != CORE_OK)
     {
@@ -82,7 +78,7 @@ static int _gtpv1_u_recv_cb(sock_id sock, void *data)
         return -1;
     }
 
-    d_trace(50, "[GTP] Receive : ");
+    d_trace(50, "[SGW] RECV : ");
     d_trace_hex(50, pkbuf->payload, pkbuf->len);
 
     gtp_h = (gtp_header_t *)pkbuf->payload;
@@ -90,14 +86,14 @@ static int _gtpv1_u_recv_cb(sock_id sock, void *data)
     {
         pkbuf_t *echo_rsp;
 
-        d_trace(3, "Recive ECHO-REQ\n");
+        d_trace(3, "[SGW] RECV : ECHO-REQ\n");
         echo_rsp = gtp_handle_echo_req(pkbuf);
         if (echo_rsp)
         {
             ssize_t sent;
 
             /* Echo reply */
-            d_trace(3, "Send ECHO-RSP\n");
+            d_trace(3, "[SGW] SEND : ECHO-RSP\n");
 
             sent = core_sendto(sock,
                     echo_rsp->payload, echo_rsp->len, 0, &from);
@@ -112,7 +108,12 @@ static int _gtpv1_u_recv_cb(sock_id sock, void *data)
                 gtp_h->type == GTPU_MSGTYPE_END_MARKER)
     {
         teid = ntohl(gtp_h->teid);
-        d_trace(50, "[GTP-U] Receive TEID[0x%x]\n", teid);
+        if (gtp_h->type == GTPU_MSGTYPE_GPDU)
+            d_trace(3, "[SGW] RECV : GPDU\n");
+        else if (gtp_h->type == GTPU_MSGTYPE_END_MARKER)
+            d_trace(3, "[SGW] RECV : End Marker\n");
+
+        d_trace(5, "    TEID[0x%x]\n", teid);
 
         tunnel = sgw_tunnel_find_by_teid(teid);
         if (!tunnel)
@@ -133,20 +134,22 @@ static int _gtpv1_u_recv_cb(sock_id sock, void *data)
                 GTP_F_TEID_SGW_GTP_U_FOR_UL_DATA_FORWARDING)
         {
             sgw_tunnel_t *s5u_tunnel = NULL;
-            d_trace(50, "[GTP-S1U] Receive TEID[0x%x]\n", teid);
 
             s5u_tunnel = sgw_s5u_tunnel_in_bearer(bearer);
             d_assert(s5u_tunnel, pkbuf_free(pkbuf); return 0, "Null param");
             gtp_h->teid = htonl(s5u_tunnel->remote_teid);
+            d_trace(3, "[SGW] SEND : GPDU\n");
+            d_trace(5, "    S1U-Remote-TEID[0x%x]\n", s5u_tunnel->remote_teid);
             gtp_send(s5u_tunnel->gnode, pkbuf);
         }
         else if (tunnel->interface_type == GTP_F_TEID_S5_S8_SGW_GTP_U)
         {
             sgw_tunnel_t *s1u_tunnel = NULL;
-            d_trace(50, "[GTP-S5U] Receive TEID[0x%x]\n", teid);
 
             s1u_tunnel = sgw_s1u_tunnel_in_bearer(bearer);
             d_assert(s1u_tunnel, pkbuf_free(pkbuf); return 0, "Null param");
+            d_trace(3, "[SGW] SEND : GPDU\n");
+            d_trace(5, "    S5U-Remote-TEID[0x%x]\n", s1u_tunnel->remote_teid);
             if (s1u_tunnel->remote_teid)
             {
                 /* If there is buffered packet, send it first */
@@ -182,11 +185,13 @@ static int _gtpv1_u_recv_cb(sock_id sock, void *data)
 
                 if ((SGW_GET_UE_STATE(sgw_ue) & SGW_S1U_INACTIVE))
                 {
+                    d_trace(7, "    SGW-S1U Inactive\n");
                     if ( !(SGW_GET_UE_STATE(sgw_ue) & SGW_DL_NOTI_SENT))
                     {
                         event_t e;
                         status_t rv;
 
+                        d_trace(7, "    EVENT DL Data Notification\n");
                         event_set(&e, SGW_EVT_LO_DLDATA_NOTI);
                         event_set_param1(&e, (c_uintptr_t)bearer->index);
                         rv = sgw_event_send(&e);
@@ -279,6 +284,8 @@ status_t sgw_gtp_send_end_marker(sgw_bearer_t *bearer)
     s1u_tunnel = sgw_s1u_tunnel_in_bearer(bearer);
     d_assert(s1u_tunnel, return CORE_ERROR,);
 
+    d_trace(3, "[SGW] SEND : End Marker\n");
+
     pkbuf = pkbuf_alloc(0, 100 /* enough for END_MARKER; use smaller buffer */);
     d_assert(pkbuf, return CORE_ERROR,);
     h = (gtp_header_t *)pkbuf->payload;