snort: add more debug logs in vpp_daq library 07/43607/2
authorMohsin Kazmi <[email protected]>
Wed, 17 Sep 2025 12:54:25 +0000 (12:54 +0000)
committerDamjan Marion <[email protected]>
Wed, 17 Sep 2025 14:34:39 +0000 (14:34 +0000)
Type: improvement

To enable debugging information in vpp_daq, one needs to pass:
--daq-var debug

daq_vpp: daq_vpp_instantiate: creating instance 1 out of 2 with input vpp0
daq_vpp: daq_vpp_socket_connect: connecting to socket /run/vpp/snort.sock
daq_vpp: daq_vpp_socket_connect: connected to socket /run/vpp/snort.sock
daq_vpp: daq_vpp_request: send msg: { type: CONNECT, connect: { num_snort_instances: 2, daq_version: 3.0.2
daq_vpp: daq_vpp_request: recv msg: { err: 0, connect: { num_bpools: 2 } }
daq_vpp: daq_vpp_request: send msg: { type: GET_BUFFER_POOL, get_buffer_pool: { buffer_pool_index: 0 } }
daq_vpp: daq_vpp_request: recv msg: { err: 0, get_buffer_pool: { size: 320864256 } }
daq_vpp: daq_vpp_request: send msg: { type: GET_BUFFER_POOL, get_buffer_pool: { buffer_pool_index: 1 } }
daq_vpp: daq_vpp_request: recv msg: { err: 0, get_buffer_pool: { size: 320864256 } }
daq_vpp: daq_vpp_request: send msg: { type: GET_INPUT, get_input: { input_name: "vpp0" } }
daq_vpp: daq_vpp_request: recv msg: { err: 0, get_input: { input_index: 0, num_qpairs: 2, shm_size: 61440
daq_vpp: daq_vpp_request: send msg: { type: ATTACH_QPAIR, attach_qpair: { input_index: 0, qpair_index: 0 }
daq_vpp: daq_vpp_request: recv msg: { err: 0, attach_qpair: { qpair_id: { thread_id: 0, queue_id: 0 }, log
daq_vpp: daq_vpp_find_or_add_input: input vpp0 qpair 0.0: size 1024, hdr 0x7f01543bc000, enq 0x7f01543c208
daq_vpp: daq_vpp_request: send msg: { type: ATTACH_QPAIR, attach_qpair: { input_index: 0, qpair_index: 1 }
daq_vpp: daq_vpp_request: recv msg: { err: 0, attach_qpair: { qpair_id: { thread_id: 1, queue_id: 0 }, log
daq_vpp: daq_vpp_find_or_add_input: input vpp0 qpair 1.0: size 1024, hdr 0x7f01543c3080, enq 0x7f01543c910
daq_vpp: daq_vpp_add_qpair_to_instance: qpair 0.0 added to instance 1
daq_vpp: daq_vpp_instantiate: creating instance 2 out of 2 with input vpp0
daq_vpp: daq_vpp_add_qpair_to_instance: qpair 1.0 added to instance 2
daq_vpp: daq_vpp_get_msg_pool_info: getting msg pool info
daq_vpp: daq_vpp_get_msg_pool_info: getting msg pool info
daq_vpp: daq_vpp_ioctl: ioctl cmd DIOCTL_GET_PRIV_DATA_LEN

Signed-off-by: Mohsin Kazmi <[email protected]>
Change-Id: I33bfbf50999bdf7658a5710da239bb0d1c4ca787

src/plugins/snort/daq/daq_vpp.h
src/plugins/snort/daq/main.c
src/plugins/snort/daq/socket.c

index 3e6828c..dbe8a6f 100644 (file)
@@ -37,7 +37,7 @@
 
 #define DEBUG(fmt, ...)                                                       \
   if (daq_vpp_main.debug)                                                     \
-    printf ("%s: " fmt "\n", "daq_vpp", ##__VA_ARGS__);
+    printf ("%s: %s: " fmt "\n", "daq_vpp", __func__, ##__VA_ARGS__);
 
 #define SET_ERROR(modinst, ...)                                               \
   daq_vpp_main.daq_base_api.set_errbuf (modinst, __VA_ARGS__)
index e6ae404..8c03ede 100644 (file)
@@ -32,7 +32,6 @@
 #include <sys/eventfd.h>
 
 #include <daq_dlt.h>
-#include <daq_module_api.h>
 
 #include "daq_vpp.h"
 
@@ -85,7 +84,9 @@ daq_vpp_destroy (void *handle)
 {
   daq_vpp_main_t *vdm = &daq_vpp_main;
   daq_vpp_ctx_t *ctx = (daq_vpp_ctx_t *) handle;
+  uint16_t instance_id = ctx->instance_id;
 
+  DEBUG ("destroying instance %u", instance_id);
   free (ctx->qpairs);
   if (ctx->epoll_fd != -1)
     close (ctx->epoll_fd);
@@ -124,6 +125,7 @@ daq_vpp_destroy (void *handle)
          free (vdm->bpools);
        }
     }
+  DEBUG ("destroyed instance %u", instance_id);
 }
 
 daq_vpp_qpair_t *
@@ -157,6 +159,8 @@ daq_vpp_add_qpair_to_instance (daq_vpp_ctx_t *ctx, daq_vpp_qpair_t *qp)
                              sizeof (daq_vpp_qpair_t *));
   ctx->qpairs[ctx->num_qpairs++] = qp;
 
+  DEBUG ("qpair %u.%u added to instance %u", qp->qpair_id.thread_id,
+        qp->qpair_id.queue_id, ctx->instance_id);
   return DAQ_SUCCESS;
 }
 
@@ -244,10 +248,6 @@ daq_vpp_instantiate (DAQ_ModuleConfig_h modcfg, DAQ_ModuleInstance_h modinst,
   strncpy (name, input_name, input_name_len);
   name[input_name_len] = 0;
 
-  rv = daq_vpp_parse_qpair_ids (ctx, end_of_name, &qpair_ids, &n_qpair_ids);
-  if (rv != DAQ_SUCCESS)
-    goto err;
-
   if (!vdm->config_parsed)
     {
       rv = daq_vpp_parse_config (ctx, modcfg);
@@ -256,6 +256,10 @@ daq_vpp_instantiate (DAQ_ModuleConfig_h modcfg, DAQ_ModuleInstance_h modinst,
       vdm->config_parsed = 1;
     }
 
+  rv = daq_vpp_parse_qpair_ids (ctx, end_of_name, &qpair_ids, &n_qpair_ids);
+  if (rv != DAQ_SUCCESS)
+    goto err;
+
   DEBUG ("creating instance %u out of %u with input %s", instance_id,
         n_instances, name);
 
@@ -682,6 +686,7 @@ static int
 daq_vpp_get_msg_pool_info (void *handle, DAQ_MsgPoolInfo_t *info)
 {
   daq_vpp_ctx_t *ctx = (daq_vpp_ctx_t *) handle;
+  DEBUG ("getting msg pool info");
   *info = ctx->msg_pool_info;
   return DAQ_SUCCESS;
 }
@@ -690,6 +695,7 @@ static int
 daq_vpp_get_stats (void __unused *handle, DAQ_Stats_t *stats)
 {
   daq_vpp_ctx_t *ctx = (daq_vpp_ctx_t *) handle;
+  DEBUG ("getting stats");
   *stats = ctx->stats;
   return DAQ_SUCCESS;
 }
@@ -698,6 +704,7 @@ static void
 daq_vpp_reset_stats (void *handle)
 {
   daq_vpp_ctx_t *ctx = (daq_vpp_ctx_t *) handle;
+  DEBUG ("resetting stats");
   ctx->stats = (DAQ_Stats_t){};
 }
 
@@ -714,6 +721,37 @@ daq_vpp_get_datalink_type (void __unused *handle)
   return DLT_IPV4;
 }
 
+static char *
+daq_vpp_ioctl_cmd_to_str (DAQ_IoctlCmd cmd)
+{
+#define IOCTL_CMD_STR(cmd)                                                    \
+  case cmd:                                                                   \
+    return #cmd;
+
+  switch (cmd)
+    {
+      IOCTL_CMD_STR (DIOCTL_GET_DEVICE_INDEX)
+      IOCTL_CMD_STR (DIOCTL_SET_FLOW_OPAQUE)
+      IOCTL_CMD_STR (DIOCTL_SET_FLOW_HA_STATE)
+      IOCTL_CMD_STR (DIOCTL_GET_FLOW_HA_STATE)
+      IOCTL_CMD_STR (DIOCTL_SET_FLOW_QOS_ID)
+      IOCTL_CMD_STR (DIOCTL_SET_PACKET_TRACE_DATA)
+      IOCTL_CMD_STR (DIOCTL_SET_PACKET_VERDICT_REASON)
+      IOCTL_CMD_STR (DIOCTL_SET_FLOW_PRESERVE)
+      IOCTL_CMD_STR (DIOCTL_GET_FLOW_TCP_SCRUBBED_SYN)
+      IOCTL_CMD_STR (DIOCTL_GET_FLOW_TCP_SCRUBBED_SYN_ACK)
+      IOCTL_CMD_STR (DIOCTL_CREATE_EXPECTED_FLOW)
+      IOCTL_CMD_STR (DIOCTL_DIRECT_INJECT_PAYLOAD)
+      IOCTL_CMD_STR (DIOCTL_DIRECT_INJECT_RESET)
+      IOCTL_CMD_STR (DIOCTL_GET_PRIV_DATA_LEN)
+      IOCTL_CMD_STR (DIOCTL_GET_CPU_PROFILE_DATA)
+      IOCTL_CMD_STR (DIOCTL_GET_SNORT_LATENCY_DATA)
+      IOCTL_CMD_STR (DIOCTL_SET_INJECT_DROP)
+    default:
+      return "UNKNOWN";
+    }
+}
+
 static int
 daq_vpp_ioctl (void *handle, DAQ_IoctlCmd cmd, void *arg, size_t arglen)
 {
@@ -721,6 +759,8 @@ daq_vpp_ioctl (void *handle, DAQ_IoctlCmd cmd, void *arg, size_t arglen)
   daq_vpp_ctx_t *ctx = (daq_vpp_ctx_t *) handle;
   DIOCTL_QueryDeviceIndex *qdi = (DIOCTL_QueryDeviceIndex *) arg;
 
+  DEBUG ("ioctl cmd %s", daq_vpp_ioctl_cmd_to_str (cmd));
+
   if (cmd == DIOCTL_GET_DEVICE_INDEX)
     {
       char name[DAQ_VPP_MAX_INST_NAME_LEN], *colon;
index 1203bbd..09e9b8d 100644 (file)
 #include "daq.h"
 #include "daq_vpp.h"
 
+static char *
+daq_vpp_msg_type_string (daq_vpp_msg_type_t t)
+{
+  switch (t)
+    {
+    case DAQ_VPP_MSG_TYPE_CONNECT:
+      return "CONNECT";
+    case DAQ_VPP_MSG_TYPE_GET_BUFFER_POOL:
+      return "GET_BUFFER_POOL";
+    case DAQ_VPP_MSG_TYPE_GET_INPUT:
+      return "GET_INPUT";
+    case DAQ_VPP_MSG_TYPE_ATTACH_QPAIR:
+      return "ATTACH_QPAIR";
+    default:
+      return "UNKNOWN";
+    }
+}
+
+static char *
+daq_vpp_daq_version_string (uint32_t v)
+{
+  static char buf[32];
+  if (v == 0)
+    return "unknown";
+  else
+    snprintf (buf, sizeof (buf), "%d.%d.%d", (v >> 24) & 0xff,
+             (v >> 16) & 0xff, (v >> 8) & 0xff);
+  return buf;
+}
+
+static char *
+daq_vpp_mode_string (daq_vpp_mode_t m)
+{
+  switch (m)
+    {
+    case DAQ_VPP_MODE_INLINE:
+      return "INLINE";
+    case DAQ_VPP_MODE_PASSIVE:
+      return "PASSIVE";
+    case DAQ_VPP_MODE_READ_FILE:
+      return "READ_FILE";
+    default:
+      return "UNKNOWN";
+    }
+}
+
+static char *
+daq_vpp_sendmsg_data_string (daq_vpp_msg_req_t *req, ssize_t sz)
+{
+  static char buf[256];
+  int n = 0;
+
+  n += snprintf (buf + n, sizeof (buf) - n, "{ type: %s",
+                daq_vpp_msg_type_string (req->type));
+
+  switch (req->type)
+    {
+    case DAQ_VPP_MSG_TYPE_CONNECT:
+      n += snprintf (
+       buf + n, sizeof (buf) - n,
+       ", connect: { num_snort_instances: %u, daq_version: %s, mode: %s }",
+       req->connect.num_snort_instances,
+       daq_vpp_daq_version_string (req->connect.daq_version),
+       daq_vpp_mode_string (req->connect.mode));
+      break;
+    case DAQ_VPP_MSG_TYPE_GET_BUFFER_POOL:
+      n += snprintf (buf + n, sizeof (buf) - n,
+                    ", get_buffer_pool: { buffer_pool_index: %u }",
+                    req->get_buffer_pool.buffer_pool_index);
+      break;
+    case DAQ_VPP_MSG_TYPE_GET_INPUT:
+      n += snprintf (buf + n, sizeof (buf) - n,
+                    ", get_input: { input_name: \"%s\" }",
+                    req->get_input.input_name);
+      break;
+    case DAQ_VPP_MSG_TYPE_ATTACH_QPAIR:
+      n += snprintf (buf + n, sizeof (buf) - n,
+                    ", attach_qpair: { input_index: %u, qpair_index: %u }",
+                    req->attach_qpair.input_index,
+                    req->attach_qpair.qpair_index);
+      break;
+    default:
+      n += snprintf (buf + n, sizeof (buf) - n, ", unknown");
+      break;
+    }
+
+  n += snprintf (buf + n, sizeof (buf) - n, " }");
+
+  if (n >= sizeof (buf))
+    return "<truncated>";
+
+  return buf;
+}
+
+static char *
+daq_vpp_recvmsg_data_string (daq_vpp_msg_reply_t *reply, ssize_t sz)
+{
+  static char buf[256];
+  int n = 0;
+
+  n += snprintf (buf + n, sizeof (buf) - n, "{ err: %d", reply->err);
+
+  switch (reply->type)
+    {
+    case DAQ_VPP_MSG_TYPE_CONNECT:
+      n +=
+       snprintf (buf + n, sizeof (buf) - n, ", connect: { num_bpools: %u }",
+                 reply->connect.num_bpools);
+      break;
+    case DAQ_VPP_MSG_TYPE_GET_BUFFER_POOL:
+      n += snprintf (buf + n, sizeof (buf) - n,
+                    ", get_buffer_pool: { size: %lu }",
+                    reply->get_buffer_pool.size);
+      break;
+    case DAQ_VPP_MSG_TYPE_GET_INPUT:
+      n += snprintf (
+       buf + n, sizeof (buf) - n,
+       ", get_input: { input_index: %u, num_qpairs: %u, shm_size: %lu }",
+       reply->get_input.input_index, reply->get_input.num_qpairs,
+       reply->get_input.shm_size);
+      break;
+    case DAQ_VPP_MSG_TYPE_ATTACH_QPAIR:
+      n += snprintf (buf + n, sizeof (buf) - n,
+                    ", attach_qpair: { qpair_id: { thread_id: %u, "
+                    "queue_id: %u }, log2_queue_size: %u, "
+                    "qpair_header_offset: %u, enq_ring_offset: %u, "
+                    "deq_ring_offset: %u }",
+                    reply->attach_qpair.qpair_id.thread_id,
+                    reply->attach_qpair.qpair_id.queue_id,
+                    reply->attach_qpair.log2_queue_size,
+                    reply->attach_qpair.qpair_header_offset,
+                    reply->attach_qpair.enq_ring_offset,
+                    reply->attach_qpair.deq_ring_offset);
+      break;
+    default:
+      n += snprintf (buf + n, sizeof (buf) - n, ", unknown");
+      break;
+    }
+
+  n += snprintf (buf + n, sizeof (buf) - n, " }");
+
+  if (n >= sizeof (buf))
+    return "<truncated>";
+
+  return buf;
+}
+
 static daq_vpp_rv_t
 daq_vpp_request (daq_vpp_msg_req_t *req, daq_vpp_msg_reply_t *reply, int n_fds,
                 int fds[])
@@ -44,6 +191,7 @@ daq_vpp_request (daq_vpp_msg_req_t *req, daq_vpp_msg_reply_t *reply, int n_fds,
   struct cmsghdr *cmsg;
   ssize_t rv;
 
+  DEBUG ("send msg: %s", daq_vpp_sendmsg_data_string (req, req_msg_sz));
   if (send (vdm->socket_fd, req, req_msg_sz, 0) != req_msg_sz)
     return DAQ_VPP_ERR_SOCKET;
 
@@ -60,6 +208,8 @@ daq_vpp_request (daq_vpp_msg_req_t *req, daq_vpp_msg_reply_t *reply, int n_fds,
   if (rv != sizeof (daq_vpp_msg_reply_t))
     return DAQ_VPP_ERR_SOCKET;
 
+  DEBUG ("recv msg: %s",
+        daq_vpp_recvmsg_data_string (reply, sizeof (daq_vpp_msg_reply_t)));
   cmsg = CMSG_FIRSTHDR (&mh);
   while (cmsg)
     {
@@ -81,15 +231,18 @@ daq_vpp_socket_disconnect ()
 {
   daq_vpp_main_t *vdm = &daq_vpp_main;
 
+  DEBUG ("disconnecting...");
   if (vdm->bpools)
     free (vdm->bpools);
 
   if (vdm->socket_fd > -1)
     {
+      DEBUG ("closing socket %s", vdm->socket_name);
       close (vdm->socket_fd);
       vdm->socket_fd = -1;
     }
-  vdm->connected = 1;
+  vdm->connected = 0;
+  DEBUG ("disconnected");
 }
 
 daq_vpp_rv_t
@@ -100,6 +253,8 @@ daq_vpp_socket_connect ()
   struct sockaddr_un sun = { .sun_family = AF_UNIX };
   int fd;
 
+  DEBUG ("connecting to socket %s", vdm->socket_name);
+
   fd = socket (AF_UNIX, SOCK_SEQPACKET, 0);
 
   if (fd < 0)
@@ -114,6 +269,9 @@ daq_vpp_socket_connect ()
     }
 
   vdm->socket_fd = fd;
+
+  DEBUG ("connected to socket %s", vdm->socket_name);
+
   return DAQ_VPP_OK;
 }
 
@@ -295,9 +453,9 @@ daq_vpp_find_or_add_input (daq_vpp_ctx_t *ctx, char *name,
                            qp->qpair_id.thread_id, qp->qpair_id.queue_id);
          goto err;
        }
-
-      DEBUG ("qpair %u.%u added, size %u", qp->qpair_id.thread_id,
-            qp->qpair_id.queue_id, qp->queue_size);
+      DEBUG ("input %s qpair %u.%u: size %u, hdr %p, enq %p, deq %p", name,
+            qp->qpair_id.thread_id, qp->qpair_id.queue_id, qp->queue_size,
+            qp->hdr, qp->enq_ring, qp->deq_ring);
     }
 
   vdm->inputs =