ikev2: better logging 63/24863/2
authorFilip Tehlar <ftehlar@cisco.com>
Sun, 20 Oct 2019 10:38:13 +0000 (10:38 +0000)
committerDamjan Marion <dmarion@me.com>
Mon, 10 Feb 2020 11:57:37 +0000 (11:57 +0000)
Type: refactor

Change-Id: Iedcb24684c54f4d78583ab3aa3db1097e73df248
Signed-off-by: Filip Tehlar <ftehlar@cisco.com>
src/plugins/ikev2/ikev2.c
src/plugins/ikev2/ikev2_cli.c
src/plugins/ikev2/ikev2_crypto.c
src/plugins/ikev2/ikev2_payload.c
src/plugins/ikev2/ikev2_priv.h

index 03448b9..ee0b11e 100644 (file)
@@ -37,7 +37,7 @@ static int ikev2_delete_tunnel_interface (vnet_main_t * vnm,
 
 #define ikev2_set_state(sa, v) do { \
     (sa)->state = v; \
-    clib_warning("sa state changed to " #v); \
+    ikev2_elog_sa_state("ispi %lx SA state changed to " #v, sa->ispi); \
   } while(0);
 
 typedef struct
@@ -171,9 +171,6 @@ ikev2_select_proposal (ikev2_sa_proposal_t * proposals,
        }
     }
 
-    clib_warning ("bitmap is %x mandatory is %x optional is %x",
-                 bitmap, mandatory_bitmap, optional_bitmap);
-
     if ((bitmap & mandatory_bitmap) == mandatory_bitmap &&
        (bitmap & ~optional_bitmap) == 0)
       {
@@ -346,8 +343,6 @@ ikev2_generate_sa_init_data (ikev2_sa_t * sa)
 
   if (!t)
     {
-      clib_warning ("unknown dh data group %u (data len %u)", sa->dh_group,
-                   vec_len (sa->i_dh_data));
       sa->dh_group = IKEV2_TRANSFORM_DH_TYPE_NONE;
       return;
     }
@@ -421,8 +416,6 @@ ikev2_complete_sa_data (ikev2_sa_t * sa, ikev2_sa_t * sai)
 
   if (!t)
     {
-      clib_warning ("unknown dh data group %u (data len %u)", sa->dh_group,
-                   vec_len (sa->i_dh_data));
       sa->dh_group = IKEV2_TRANSFORM_DH_TYPE_NONE;
       return;
     }
@@ -596,13 +589,10 @@ ikev2_process_sa_init_req (vlib_main_t * vm, ikev2_sa_t * sa,
   u32 len = clib_net_to_host_u32 (ike->length);
   u8 payload = ike->nextpayload;
 
-  clib_warning ("ispi %lx rspi %lx nextpayload %x version %x "
-               "exchange %x flags %x msgid %x length %u",
-               clib_net_to_host_u64 (ike->ispi),
-               clib_net_to_host_u64 (ike->rspi),
-               payload, ike->version,
-               ike->exchange, ike->flags,
-               clib_net_to_host_u32 (ike->msgid), len);
+  ikev2_elog_exchange ("ispi %lx rspi %lx IKE_INIT request received "
+                      "from %d.%d.%d.%d",
+                      clib_net_to_host_u64 (ike->ispi),
+                      clib_net_to_host_u64 (ike->rspi), sa->iaddr.as_u32);
 
   sa->ispi = clib_net_to_host_u64 (ike->ispi);
 
@@ -646,8 +636,8 @@ ikev2_process_sa_init_req (vlib_main_t * vm, ikev2_sa_t * sa,
        }
       else
        {
-         clib_warning ("unknown payload %u flags %x length %u", payload,
-                       ikep->flags, plen);
+         ikev2_elog_uint (IKEV2_LOG_ERROR, "Unknown payload! type=%d",
+                          payload);
          if (ikep->flags & IKEV2_PAYLOAD_FLAG_CRITICAL)
            {
              ikev2_set_state (sa, IKEV2_STATE_NOTIFY_AND_DELETE);
@@ -671,17 +661,13 @@ ikev2_process_sa_init_resp (vlib_main_t * vm, ikev2_sa_t * sa,
   u32 len = clib_net_to_host_u32 (ike->length);
   u8 payload = ike->nextpayload;
 
-  clib_warning ("ispi %lx rspi %lx nextpayload %x version %x "
-               "exchange %x flags %x msgid %x length %u",
-               clib_net_to_host_u64 (ike->ispi),
-               clib_net_to_host_u64 (ike->rspi),
-               payload, ike->version,
-               ike->exchange, ike->flags,
-               clib_net_to_host_u32 (ike->msgid), len);
-
   sa->ispi = clib_net_to_host_u64 (ike->ispi);
   sa->rspi = clib_net_to_host_u64 (ike->rspi);
 
+  ikev2_elog_exchange ("ispi %lx rspi %lx IKE_INIT response received "
+                      "from %d.%d.%d.%d", sa->ispi, sa->rspi,
+                      sa->raddr.as_u32);
+
   /* store whole IKE payload - needed for PSK auth */
   vec_free (sa->last_sa_init_res_packet_data);
   vec_add (sa->last_sa_init_res_packet_data, ike, len);
@@ -728,8 +714,8 @@ ikev2_process_sa_init_resp (vlib_main_t * vm, ikev2_sa_t * sa,
        }
       else
        {
-         clib_warning ("unknown payload %u flags %x length %u", payload,
-                       ikep->flags, plen);
+         ikev2_elog_uint (IKEV2_LOG_ERROR, "Unknown payload! type=%d",
+                          payload);
          if (ikep->flags & IKEV2_PAYLOAD_FLAG_CRITICAL)
            {
              ikev2_set_state (sa, IKEV2_STATE_NOTIFY_AND_DELETE);
@@ -767,13 +753,12 @@ ikev2_decrypt_sk_payload (ikev2_sa_t * sa, ike_header_t * ike, u8 * payload)
 
       if (*payload == IKEV2_PAYLOAD_SK)
        {
-         clib_warning ("received IKEv2 payload SK, len %u", plen - 4);
          last_payload = *payload;
        }
       else
        {
-         clib_warning ("unknown payload %u flags %x length %u", payload,
-                       ikep->flags, plen);
+         ikev2_elog_uint (IKEV2_LOG_ERROR, "Unknown payload! type=%d",
+                          *payload);
          if (ikep->flags & IKEV2_PAYLOAD_FLAG_CRITICAL)
            {
              sa->unsupported_cp = *payload;
@@ -787,7 +772,7 @@ ikev2_decrypt_sk_payload (ikev2_sa_t * sa, ike_header_t * ike, u8 * payload)
 
   if (last_payload != IKEV2_PAYLOAD_SK)
     {
-      clib_warning ("Last payload must be SK");
+      ikev2_elog_error ("Last payload must be SK");
       return 0;
     }
 
@@ -799,7 +784,7 @@ ikev2_decrypt_sk_payload (ikev2_sa_t * sa, ike_header_t * ike, u8 * payload)
 
   if (memcmp (hmac, &ikep->payload[plen], tr_integ->key_trunc))
     {
-      clib_warning ("message integrity check failed");
+      ikev2_elog_error ("message integrity check failed");
       vec_free (hmac);
       return 0;
     }
@@ -845,6 +830,9 @@ ikev2_initial_contact_cleanup (ikev2_sa_t * sa)
 
   vec_free (delete);
   sa->initial_contact = 0;
+
+  km->log_level = IKEV2_LOG_ERROR;
+  km->log_class = vlib_log_register_class ("ikev2", 0);
 }
 
 static void
@@ -852,20 +840,16 @@ ikev2_process_auth_req (vlib_main_t * vm, ikev2_sa_t * sa, ike_header_t * ike)
 {
   ikev2_child_sa_t *first_child_sa;
   int p = 0;
-  u32 len = clib_net_to_host_u32 (ike->length);
   u8 payload = ike->nextpayload;
   u8 *plaintext = 0;
-
   ike_payload_header_t *ikep;
   u32 plen;
 
-  clib_warning ("ispi %lx rspi %lx nextpayload %x version %x "
-               "exchange %x flags %x msgid %x length %u",
-               clib_net_to_host_u64 (ike->ispi),
-               clib_net_to_host_u64 (ike->rspi),
-               payload, ike->version,
-               ike->exchange, ike->flags,
-               clib_net_to_host_u32 (ike->msgid), len);
+  ikev2_elog_exchange ("ispi %lx rspi %lx EXCHANGE_IKE_AUTH received "
+                      "from %d.%d.%d.%d", clib_host_to_net_u64 (ike->ispi),
+                      clib_host_to_net_u64 (ike->rspi),
+                      sa->is_initiator ? sa->raddr.as_u32 : sa->
+                      iaddr.as_u32);
 
   ikev2_calc_keys (sa);
 
@@ -902,7 +886,6 @@ ikev2_process_auth_req (vlib_main_t * vm, ikev2_sa_t * sa, ike_header_t * ike)
 
       if (payload == IKEV2_PAYLOAD_SA) /* 33 */
        {
-         clib_warning ("received payload SA, len %u", plen - sizeof (*ikep));
          if (sa->is_initiator)
            {
              ikev2_sa_free_proposal_vector (&first_child_sa->r_proposals);
@@ -921,9 +904,6 @@ ikev2_process_auth_req (vlib_main_t * vm, ikev2_sa_t * sa, ike_header_t * ike)
          sa->i_id.type = id->id_type;
          vec_free (sa->i_id.data);
          vec_add (sa->i_id.data, id->payload, plen - sizeof (*id));
-
-         clib_warning ("received payload IDi, len %u id_type %u",
-                       plen - sizeof (*id), id->id_type);
        }
       else if (payload == IKEV2_PAYLOAD_IDR)   /* 36 */
        {
@@ -932,9 +912,6 @@ ikev2_process_auth_req (vlib_main_t * vm, ikev2_sa_t * sa, ike_header_t * ike)
          sa->r_id.type = id->id_type;
          vec_free (sa->r_id.data);
          vec_add (sa->r_id.data, id->payload, plen - sizeof (*id));
-
-         clib_warning ("received payload IDr len %u id_type %u",
-                       plen - sizeof (*id), id->id_type);
        }
       else if (payload == IKEV2_PAYLOAD_AUTH)  /* 39 */
        {
@@ -952,9 +929,6 @@ ikev2_process_auth_req (vlib_main_t * vm, ikev2_sa_t * sa, ike_header_t * ike)
              vec_free (sa->i_auth.data);
              vec_add (sa->i_auth.data, a->payload, plen - sizeof (*a));
            }
-
-         clib_warning ("received payload AUTH, len %u auth_type %u",
-                       plen - sizeof (*a), a->auth_method);
        }
       else if (payload == IKEV2_PAYLOAD_NOTIFY)        /* 41 */
        {
@@ -971,25 +945,18 @@ ikev2_process_auth_req (vlib_main_t * vm, ikev2_sa_t * sa, ike_header_t * ike)
        }
       else if (payload == IKEV2_PAYLOAD_TSI)   /* 44 */
        {
-         clib_warning ("received payload TSi, len %u",
-                       plen - sizeof (*ikep));
-
          vec_free (first_child_sa->tsi);
          first_child_sa->tsi = ikev2_parse_ts_payload (ikep);
        }
       else if (payload == IKEV2_PAYLOAD_TSR)   /* 45 */
        {
-         clib_warning ("received payload TSr, len %u",
-                       plen - sizeof (*ikep));
-
          vec_free (first_child_sa->tsr);
          first_child_sa->tsr = ikev2_parse_ts_payload (ikep);
        }
       else
        {
-         clib_warning ("unknown payload %u flags %x length %u data %u",
-                       payload, ikep->flags, plen - 4,
-                       format_hex_bytes, ikep->payload, plen - 4);
+         ikev2_elog_uint (IKEV2_LOG_ERROR, "Unknown payload! type=%d",
+                          payload);
 
          if (ikep->flags & IKEV2_PAYLOAD_FLAG_CRITICAL)
            {
@@ -1012,20 +979,14 @@ ikev2_process_informational_req (vlib_main_t * vm, ikev2_sa_t * sa,
                                 ike_header_t * ike)
 {
   int p = 0;
-  u32 len = clib_net_to_host_u32 (ike->length);
   u8 payload = ike->nextpayload;
   u8 *plaintext = 0;
-
   ike_payload_header_t *ikep;
   u32 plen;
 
-  clib_warning ("ispi %lx rspi %lx nextpayload %x version %x "
-               "exchange %x flags %x msgid %x length %u",
-               clib_net_to_host_u64 (ike->ispi),
-               clib_net_to_host_u64 (ike->rspi),
-               payload, ike->version,
-               ike->exchange, ike->flags,
-               clib_net_to_host_u32 (ike->msgid), len);
+  ikev2_elog_exchange ("ispi %lx rspi %lx INFORMATIONAL received "
+                      "from %d.%d.%d.%d", clib_host_to_net_u64 (ike->ispi),
+                      clib_host_to_net_u64 (ike->rspi), sa->iaddr.as_u32);
 
   plaintext = ikev2_decrypt_sk_payload (sa, ike, &payload);
 
@@ -1059,10 +1020,8 @@ ikev2_process_informational_req (vlib_main_t * vm, ikev2_sa_t * sa,
        }
       else
        {
-         clib_warning ("unknown payload %u flags %x length %u data %u",
-                       payload, ikep->flags, plen - 4,
-                       format_hex_bytes, ikep->payload, plen - 4);
-
+         ikev2_elog_uint (IKEV2_LOG_ERROR, "Unknown payload! type=%d",
+                          payload);
          if (ikep->flags & IKEV2_PAYLOAD_FLAG_CRITICAL)
            {
              sa->unsupported_cp = payload;
@@ -1083,7 +1042,6 @@ ikev2_process_create_child_sa_req (vlib_main_t * vm, ikev2_sa_t * sa,
                                   ike_header_t * ike)
 {
   int p = 0;
-  u32 len = clib_net_to_host_u32 (ike->length);
   u8 payload = ike->nextpayload;
   u8 *plaintext = 0;
   u8 rekeying = 0;
@@ -1097,13 +1055,9 @@ ikev2_process_create_child_sa_req (vlib_main_t * vm, ikev2_sa_t * sa,
   ikev2_sa_proposal_t *proposal = 0;
   ikev2_child_sa_t *child_sa;
 
-  clib_warning ("ispi %lx rspi %lx nextpayload %x version %x "
-               "exchange %x flags %x msgid %x length %u",
-               clib_net_to_host_u64 (ike->ispi),
-               clib_net_to_host_u64 (ike->rspi),
-               payload, ike->version,
-               ike->exchange, ike->flags,
-               clib_net_to_host_u32 (ike->msgid), len);
+  ikev2_elog_exchange ("ispi %lx rspi %lx CREATE_CHILD_SA received "
+                      "from %d.%d.%d.%d", clib_host_to_net_u64 (ike->ispi),
+                      clib_host_to_net_u64 (ike->rspi), sa->raddr.as_u32);
 
   plaintext = ikev2_decrypt_sk_payload (sa, ike, &payload);
 
@@ -1154,10 +1108,8 @@ ikev2_process_create_child_sa_req (vlib_main_t * vm, ikev2_sa_t * sa,
        }
       else
        {
-         clib_warning ("unknown payload %u flags %x length %u data %u",
-                       payload, ikep->flags, plen - 4,
-                       format_hex_bytes, ikep->payload, plen - 4);
-
+         ikev2_elog_uint (IKEV2_LOG_ERROR, "Unknown payload! type=%d",
+                          payload);
          if (ikep->flags & IKEV2_PAYLOAD_FLAG_CRITICAL)
            {
              sa->unsupported_cp = payload;
@@ -1194,7 +1146,8 @@ ikev2_process_create_child_sa_req (vlib_main_t * vm, ikev2_sa_t * sa,
       child_sa = ikev2_sa_get_child (sa, n->spi, n->protocol_id, 1);
       if (!child_sa)
        {
-         clib_warning ("child SA spi %lx not found", n->spi);
+         ikev2_elog_uint (IKEV2_LOG_ERROR, "child SA spi %lx not found",
+                          n->spi);
          goto cleanup_and_exit;
        }
       vec_add2 (sa->rekey, rekey, 1);
@@ -1356,8 +1309,9 @@ ikev2_sa_auth (ikev2_sa_t * sa)
   if (!(sa->i_auth.method == IKEV2_AUTH_METHOD_SHARED_KEY_MIC ||
        sa->i_auth.method == IKEV2_AUTH_METHOD_RSA_SIG))
     {
-      clib_warning ("unsupported authentication method %u",
-                   sa->i_auth.method);
+      ikev2_elog_uint (IKEV2_LOG_ERROR,
+                      "unsupported authentication method %u",
+                      sa->i_auth.method);
       ikev2_set_state (sa, IKEV2_STATE_AUTH_FAILED);
       return;
     }
@@ -1457,6 +1411,8 @@ ikev2_sa_auth (ikev2_sa_t * sa)
     }
   else
     {
+      ikev2_elog_uint (IKEV2_LOG_ERROR, "authentication failed, no matching "
+                      "profile found! ispi %lx", sa->ispi);
       ikev2_set_state (sa, IKEV2_STATE_AUTH_FAILED);
     }
   vec_free (psk);
@@ -1478,8 +1434,9 @@ ikev2_sa_auth_init (ikev2_sa_t * sa)
   if (!(sa->i_auth.method == IKEV2_AUTH_METHOD_SHARED_KEY_MIC ||
        sa->i_auth.method == IKEV2_AUTH_METHOD_RSA_SIG))
     {
-      clib_warning ("unsupported authentication method %u",
-                   sa->i_auth.method);
+      ikev2_elog_uint (IKEV2_LOG_ERROR,
+                      "unsupported authentication method %u",
+                      sa->i_auth.method);
       ikev2_set_state (sa, IKEV2_STATE_AUTH_FAILED);
       return;
     }
@@ -1558,9 +1515,9 @@ ikev2_add_tunnel_from_main (ikev2_add_ipsec_tunnel_args_t * a)
 
   if (rv)
     {
-      clib_warning ("installing ipip tunnel failed! loc:%U rem:%U",
-                   format_ip4_address, &a->local_ip,
-                   format_ip4_address, &a->remote_ip);
+      ikev2_elog_peers (IKEV2_LOG_ERROR, "installing ipip tunnel failed! "
+                       "loc:%d.%d.%d.%d rem:%d.%d.%d.%d",
+                       a->local_ip.ip4.as_u32, a->remote_ip.ip4.as_u32);
       return;
     }
 
@@ -1771,10 +1728,10 @@ ikev2_create_tunnel_interface (vnet_main_t * vnm,
     }
 
   if (thread_index & 0xffffffc0)
-    clib_warning ("error: thread index exceeds max range 0x3f!");
+    ikev2_elog_error ("error: thread index exceeds max range 0x3f!");
 
   if (child_index & 0xfffff000 || sa_index & 0xfffff000)
-    clib_warning ("error: sa/child index exceeds max range 0xfff!");
+    ikev2_elog_error ("error: sa/child index exceeds max range 0xfff!");
 
   child->local_sa_id =
     a.local_sa_id =
@@ -2174,17 +2131,21 @@ ikev2_retransmit_sa_init (ike_header_t * ike,
                       ike->length = tmp->length;
                       clib_memcpy_fast(ike->payload, tmp->payload,
                              clib_net_to_host_u32(tmp->length) - sizeof(*ike));
-                      clib_warning("IKE_SA_INIT retransmit from %U to %U",
-                                   format_ip4_address, &raddr,
-                                   format_ip4_address, &iaddr);
+                      ikev2_elog_uint_peers (IKEV2_LOG_DEBUG,
+                                             "ispi %lx IKE_SA_INIT retransmit "
+                                             "from %d.%d.%d.%d to %d.%d.%d.%d",
+                                             ike->ispi,
+                                             raddr.as_u32, iaddr.as_u32);
                       return 1;
                     }
                   /* else ignore req */
                   else
                     {
-                      clib_warning("IKE_SA_INIT ignore from %U to %U",
-                                   format_ip4_address, &raddr,
-                                   format_ip4_address, &iaddr);
+                      ikev2_elog_uint_peers (IKEV2_LOG_DEBUG,
+                                             "ispi %lx IKE_SA_INIT ignore "
+                                             "from %d.%d.%d.%d to %d.%d.%d.%d",
+                                             ike->ispi,
+                                             raddr.as_u32, iaddr.as_u32);
                       return -1;
                     }
                 }
@@ -2226,21 +2187,17 @@ ikev2_retransmit_resp (ikev2_sa_t * sa, ike_header_t * ike)
       ike->length = tmp->length;
       clib_memcpy_fast (ike->payload, tmp->payload,
                        clib_net_to_host_u32 (tmp->length) - sizeof (*ike));
-      clib_warning ("IKE msgid %u retransmit from %U to %U",
-                   msg_id,
-                   format_ip4_address, &sa->raddr,
-                   format_ip4_address, &sa->iaddr);
+      ikev2_elog_uint_peers (IKEV2_LOG_DEBUG, "IKE retransmit msgid %d",
+                            msg_id, sa->raddr.as_u32, sa->iaddr.as_u32);
       return 1;
     }
   /* old req ignore */
   else
     {
-      clib_warning ("IKE msgid %u req ignore from %U to %U",
-                   msg_id,
-                   format_ip4_address, &sa->raddr,
-                   format_ip4_address, &sa->iaddr);
-      return -1;
+      ikev2_elog_uint_peers (IKEV2_LOG_DEBUG, "IKE req ignore msgid %d",
+                            msg_id, sa->raddr.as_u32, sa->iaddr.as_u32);
     }
+  return -1;
 }
 
 
@@ -2583,10 +2540,11 @@ ikev2_node_fn (vlib_main_t * vm,
            }
          else
            {
-             clib_warning ("IKEv2 exchange %u packet received from %U to %U",
-                           ike0->exchange,
-                           format_ip4_address, ip40->src_address.as_u8,
-                           format_ip4_address, ip40->dst_address.as_u8);
+             ikev2_elog_uint_peers (IKEV2_LOG_WARNING, "IKEv2 exchange %d "
+                                    "received from %d.%d.%d.%d to %d.%d.%d.%d",
+                                    ike0->exchange,
+                                    ip40->src_address.as_u32,
+                                    ip40->dst_address.as_u32);
            }
 
        dispatch0:
@@ -2717,7 +2675,7 @@ ikev2_set_initiator_proposals (vlib_main_t * vm, ikev2_sa_t * sa,
   }
   if (error)
     {
-      clib_warning
+      ikev2_elog_error
        ("Didn't find any supported algorithm for IKEV2_TRANSFORM_TYPE_INTEG");
       r = clib_error_return (0, "Unsupported algorithm");
       return r;
@@ -3256,6 +3214,9 @@ ikev2_initiate_sa_init (vlib_main_t * vm, u8 * name)
 
     ikev2_send_ike (vm, if_ip, &p->responder.ip4, bi0, len);
 
+    ikev2_elog_exchange ("ispi %lx rspi %lx IKEV2_EXCHANGE_SA_INIT sent to "
+                        "%d.%d.%d.%d", clib_host_to_net_u64 (sa0->ispi), 0,
+                        p->responder.ip4.as_u32);
   }
 
   return 0;
@@ -3548,8 +3509,8 @@ ikev2_mngr_process_child_sa (ikev2_sa_t * sa, ikev2_child_sa_t * csa)
          else if (csa->rekey_retries > 0)
            {
              csa->rekey_retries--;
-             clib_warning ("Rekeying Child SA 0x%x, retries left %d",
-                           csa->i_proposals->spi, csa->rekey_retries);
+             ikev2_log_debug ("Rekeying Child SA 0x%x, retries left %d",
+                              csa->i_proposals->spi, csa->rekey_retries);
              if (csa->rekey_retries == 0)
                {
                  csa->rekey_retries = -1;
@@ -3568,6 +3529,21 @@ ikev2_mngr_process_child_sa (ikev2_sa_t * sa, ikev2_child_sa_t * csa)
   return res;
 }
 
+int
+ikev2_set_log_level (ikev2_log_level_t log_level)
+{
+  ikev2_main_t *km = &ikev2_main;
+
+  if (log_level >= IKEV2_LOG_MAX)
+    {
+      ikev2_log_error ("unknown logging level %d", log_level);
+      return -1;
+    }
+
+  km->log_level = log_level;
+  return 0;
+}
+
 static void
 ikev2_mngr_process_ipsec_sa (ipsec_sa_t * ipsec_sa)
 {
index 0933667..2ca1a5c 100644 (file)
@@ -589,6 +589,42 @@ ikev2_cli_reference (void)
 {
 }
 
+static clib_error_t *
+ikev2_set_log_level_command_fn (vlib_main_t * vm,
+                               unformat_input_t * input,
+                               vlib_cli_command_t * cmd)
+{
+  unformat_input_t _line_input, *line_input = &_line_input;
+  u8 log_level = IKEV2_LOG_NONE;
+  clib_error_t *error = 0;
+
+  /* Get a line of input. */
+  if (!unformat_user (input, unformat_line_input, line_input))
+    return 0;
+
+  if (!unformat (line_input, "%d", &log_level))
+    {
+      error = clib_error_return (0, "unknown input '%U'",
+                                format_unformat_error, line_input);
+      goto done;
+    }
+  int rc = ikev2_set_log_level (log_level);
+  if (rc < 0)
+    error = clib_error_return (0, "setting log level failed!");
+
+done:
+  unformat_free (line_input);
+  return error;
+}
+
+/* *INDENT-OFF* */
+VLIB_CLI_COMMAND (ikev2_set_log_level_command, static) = {
+  .path = "ikev2 set logging level",
+  .function = ikev2_set_log_level_command_fn,
+  .short_help = "ikev2 set logging level <0-5>",
+};
+/* *INDENT-ON* */
+
 /*
  * fd.io coding-style-patch-verification: ON
  *
index 49629a5..26ff433 100644 (file)
@@ -342,11 +342,11 @@ ikev2_calc_integr (ikev2_sa_transform_t * tr, v8 * key, u8 * data, int len)
 
   if (tr->md == EVP_sha1 ())
     {
-      clib_warning ("integrity checking with sha1");
+      ikev2_elog_debug ("integrity checking with sha1");
     }
   else if (tr->md == EVP_sha256 ())
     {
-      clib_warning ("integrity checking with sha256");
+      ikev2_elog_debug ("integrity checking with sha256");
     }
 
   /* verify integrity of data */
@@ -389,7 +389,7 @@ ikev2_decrypt_data (ikev2_sa_t * sa, u8 * data, int len)
   /* check if data is multiplier of cipher block size */
   if (len % block_size)
     {
-      clib_warning ("wrong data length");
+      ikev2_elog_error ("wrong data length");
       return 0;
     }
 
@@ -772,7 +772,7 @@ ikev2_load_cert_file (u8 * file)
   fp = fopen ((char *) file, "r");
   if (!fp)
     {
-      clib_warning ("open %s failed", file);
+      ikev2_log_error ("open %s failed", file);
       goto end;
     }
 
@@ -780,13 +780,13 @@ ikev2_load_cert_file (u8 * file)
   fclose (fp);
   if (x509 == NULL)
     {
-      clib_warning ("read cert %s failed", file);
+      ikev2_log_error ("read cert %s failed", file);
       goto end;
     }
 
   pkey = X509_get_pubkey (x509);
   if (pkey == NULL)
-    clib_warning ("get pubkey %s failed", file);
+    ikev2_log_error ("get pubkey %s failed", file);
 
 end:
   return pkey;
@@ -801,14 +801,14 @@ ikev2_load_key_file (u8 * file)
   fp = fopen ((char *) file, "r");
   if (!fp)
     {
-      clib_warning ("open %s failed", file);
+      ikev2_log_error ("open %s failed", file);
       goto end;
     }
 
   pkey = PEM_read_PrivateKey (fp, NULL, NULL, NULL);
   fclose (fp);
   if (pkey == NULL)
-    clib_warning ("read %s failed", file);
+    ikev2_log_error ("read %s failed", file);
 
 end:
   return pkey;
index 509483a..56bb652 100644 (file)
@@ -187,11 +187,6 @@ ikev2_payload_add_sa (ikev2_payload_chain_t * c,
     if (spi_size)
       prop->spi[0] = clib_host_to_net_u32 (p->spi);
 
-    DBG_PLD ("proposal num %u protocol_id %u last_or_more %u spi_size %u%s%U",
-            prop->proposal_num, prop->protocol_id, prop->last_or_more,
-            prop->spi_size, prop->spi_size ? " spi_data " : "",
-            format_hex_bytes, prop->spi, prop->spi_size);
-
     vec_foreach (t, p->transforms)
     {
       vec_add2 (tr_data, tmp, sizeof (*tr) + vec_len (t->attrs));
@@ -205,13 +200,6 @@ ikev2_payload_add_sa (ikev2_payload_chain_t * c,
 
       if (vec_len (t->attrs) > 0)
        clib_memcpy_fast (tr->attributes, t->attrs, vec_len (t->attrs));
-
-      DBG_PLD
-       ("transform type %U transform_id %u last_or_more %u attr_size %u%s%U",
-        format_ikev2_transform_type, tr->transform_type, t->transform_id,
-        tr->last_or_more, vec_len (t->attrs),
-        vec_len (t->attrs) ? " attrs " : "", format_hex_bytes,
-        tr->attributes, vec_len (t->attrs));
     }
 
     prop->proposal_len =
@@ -356,12 +344,6 @@ ikev2_parse_sa_payload (ike_payload_header_t * ikep)
       int i;
       int transform_ptr;
 
-      DBG_PLD ("proposal num %u len %u last_or_more %u id %u "
-              "spi_size %u num_transforms %u",
-              sap->proposal_num, clib_net_to_host_u16 (sap->proposal_len),
-              sap->last_or_more, sap->protocol_id, sap->spi_size,
-              sap->num_transforms);
-
       /* IKE proposal should not have SPI */
       if (sap->protocol_id == IKEV2_PROTOCOL_IKE && sap->spi_size != 0)
        goto data_corrupted;
@@ -396,14 +378,6 @@ ikev2_parse_sa_payload (ike_payload_header_t * ikep)
          transform->transform_id = clib_net_to_host_u16 (tr->transform_id);
          if (tlen > sizeof (*tr))
            vec_add (transform->attrs, tr->attributes, tlen - sizeof (*tr));
-
-         DBG_PLD
-           ("transform num %u len %u last_or_more %u type %U id %u%s%U", i,
-            tlen, tr->last_or_more, format_ikev2_sa_transform, transform,
-            clib_net_to_host_u16 (tr->transform_id),
-            tlen > sizeof (*tr) ? " attrs " : "", format_hex_bytes,
-            tr->attributes, tlen - sizeof (*tr));
-
          transform_ptr += tlen;
        }
 
@@ -418,7 +392,7 @@ ikev2_parse_sa_payload (ike_payload_header_t * ikep)
   return v;
 
 data_corrupted:
-  DBG_PLD ("SA payload data corrupted");
+  ikev2_elog_detail ("SA payload data corrupted");
   ikev2_sa_free_proposal_vector (&v);
   return 0;
 }
@@ -433,10 +407,11 @@ ikev2_parse_ts_payload (ike_payload_header_t * ikep)
   for (i = 0; i < tsp->num_ts; i++)
     {
       if (tsp->ts[i].ts_type != 7)     /*  TS_IPV4_ADDR_RANGE */
-       {
-         DBG_PLD ("unsupported TS type received (%u)", tsp->ts[i].ts_type);
-         continue;
-       }
+        {
+          ikev2_elog_uint (IKEV2_LOG_ERROR,
+              "unsupported TS type received (%u)", tsp->ts[i].ts_type);
+          continue;
+        }
 
       vec_add2 (r, ts, 1);
       ts->ts_type = tsp->ts[i].ts_type;
@@ -457,11 +432,6 @@ ikev2_parse_notify_payload (ike_payload_header_t * ikep)
   ikev2_notify_t *r = 0;
   u32 spi;
 
-  DBG_PLD ("msg_type %U len %u%s%U",
-          format_ikev2_notify_msg_type, clib_net_to_host_u16 (n->msg_type),
-          plen, plen > sizeof (*n) ? " data " : "",
-          format_hex_bytes, n->payload, plen - sizeof (*n));
-
   r = vec_new (ikev2_notify_t, 1);
   r->msg_type = clib_net_to_host_u16 (n->msg_type);
   r->protocol_id = n->protocol_id;
@@ -470,7 +440,6 @@ ikev2_parse_notify_payload (ike_payload_header_t * ikep)
     {
       clib_memcpy (&spi, n->payload, n->spi_size);
       r->spi = clib_net_to_host_u32 (spi);
-      DBG_PLD ("spi %lx", r->spi);
     }
   else if (n->spi_size == 0)
     {
@@ -494,34 +463,17 @@ void
 ikev2_parse_vendor_payload (ike_payload_header_t * ikep)
 {
   u32 plen = clib_net_to_host_u16 (ikep->length);
-  int i;
-  int is_string = 1;
-
-  for (i = 0; i < plen - 4; i++)
-    if (!isprint (ikep->payload[i]))
-      is_string = 0;
-
-  DBG_PLD ("len %u data %s:%U",
-          plen,
-          is_string ? "string" : "hex",
-          is_string ? format_ascii_bytes : format_hex_bytes,
-          ikep->payload, plen - sizeof (*ikep));
+  ikev2_elog_uint (IKEV2_LOG_DEBUG, "vendor payload skipped, len %d", plen);
 }
 
 ikev2_delete_t *
 ikev2_parse_delete_payload (ike_payload_header_t * ikep)
 {
   ike_delete_payload_header_t *d = (ike_delete_payload_header_t *) ikep;
-  u32 plen = clib_net_to_host_u16 (ikep->length);
   ikev2_delete_t *r = 0, *del;
   u16 num_of_spi = clib_net_to_host_u16 (d->num_of_spi);
   u16 i = 0;
 
-  DBG_PLD ("protocol_id %u spi_size %u num_of_spi %u len %u%s%U",
-          d->protocol_id, d->spi_size, num_of_spi,
-          plen, plen > sizeof (d) ? " data " : "",
-          format_hex_bytes, d->spi, plen - sizeof (*d));
-
   if (d->protocol_id == IKEV2_PROTOCOL_IKE)
     {
       r = vec_new (ikev2_delete_t, 1);
index 630ba1b..aa85b84 100644 (file)
 #include <openssl/hmac.h>
 #include <openssl/evp.h>
 
-#define IKEV2_DEBUG_PAYLOAD 1
+#define foreach_ikev2_log_level \
+  _(0x00, LOG_NONE)             \
+  _(0x01, LOG_ERROR)            \
+  _(0x02, LOG_WARNING)          \
+  _(0x03, LOG_INFO)             \
+  _(0x04, LOG_DEBUG)            \
+  _(0x05, LOG_DETAIL)           \
 
-#if IKEV2_DEBUG_PAYLOAD == 1
-#define DBG_PLD(my_args...) clib_warning(my_args)
-#else
-#define DBG_PLD(my_args...)
-#endif
+
+typedef enum ikev2_log_level_t_
+{
+#define _(n,f) IKEV2_##f = n,
+  foreach_ikev2_log_level
+#undef _
+  IKEV2_LOG_MAX
+} ikev2_log_level_t;
+
+/* dataplane logging */
+#define _ikev2_elog(_level, _msg)                                             \
+do {                                                                          \
+  ikev2_main_t *km = &ikev2_main;                                             \
+  if (PREDICT_FALSE (km->log_level >= _level))                                \
+    {                                                                         \
+      ELOG_TYPE_DECLARE (e) =                                                 \
+        {                                                                     \
+          .format = "ikev2 " _msg,                                            \
+          .format_args = "",                                                  \
+        };                                                                    \
+      ELOG_DATA (&vlib_global_main.elog_main, e);                             \
+    }                                                                         \
+} while (0)
+
+#define ikev2_elog_sa_state(_format, _ispi)                                   \
+do {                                                                          \
+  ikev2_main_t *km = &ikev2_main;                                             \
+  if (PREDICT_FALSE (km->log_level >= IKEV2_LOG_DEBUG))                       \
+    {                                                                         \
+      ELOG_TYPE_DECLARE (e) =                                                 \
+        {                                                                     \
+          .format = "ikev2: " _format,                                        \
+          .format_args = "i8",                                                \
+        };                                                                    \
+      CLIB_PACKED(struct                                                      \
+        {                                                                     \
+          u64 ispi;                                                           \
+        }) *ed;                                                               \
+      ed = ELOG_DATA (&vlib_global_main.elog_main, e);                        \
+      ed->ispi = _ispi;                                                       \
+    }                                                                         \
+} while (0)                                                                   \
+
+#define ikev2_elog_exchange(_format, _ispi, _rspi, _addr)                     \
+do {                                                                          \
+  ikev2_main_t *km = &ikev2_main;                                             \
+  if (PREDICT_FALSE (km->log_level >= IKEV2_LOG_DEBUG))                       \
+    {                                                                         \
+      ELOG_TYPE_DECLARE (e) =                                                 \
+        {                                                                     \
+          .format = "ikev2: " _format,                                        \
+          .format_args = "i8i8i1i1i1i1",                                      \
+        };                                                                    \
+      CLIB_PACKED(struct                                                      \
+        {                                                                     \
+          u64 ispi;                                                           \
+          u64 rspi;                                                           \
+          u8 oct1;                                                            \
+          u8 oct2;                                                            \
+          u8 oct3;                                                            \
+          u8 oct4;                                                            \
+        }) *ed;                                                               \
+      ed = ELOG_DATA (&vlib_global_main.elog_main, e);                        \
+      ed->ispi = _ispi;                                                       \
+      ed->rspi = _rspi;                                                       \
+      ed->oct4 = (_addr) >> 24;                                               \
+      ed->oct3 = (_addr) >> 16;                                               \
+      ed->oct2 = (_addr) >> 8;                                                \
+      ed->oct1 = (_addr);                                                     \
+    }                                                                         \
+} while (0)                                                                   \
+
+#define ikev2_elog_uint(_level, _format, _val)                                \
+do {                                                                          \
+  ikev2_main_t *km = &ikev2_main;                                             \
+  if (PREDICT_FALSE (km->log_level >= _level))                                \
+    {                                                                         \
+      ELOG_TYPE_DECLARE (e) =                                                 \
+        {                                                                     \
+          .format = "ikev2: " _format,                                        \
+          .format_args = "i8",                                                \
+        };                                                                    \
+      CLIB_PACKED(struct                                                      \
+        {                                                                     \
+          u64 val;                                                            \
+        }) *ed;                                                               \
+      ed = ELOG_DATA (&vlib_global_main.elog_main, e);                        \
+      ed->val = _val;                                                         \
+    }                                                                         \
+} while (0)
+
+#define ikev2_elog_uint_peers(_level, _format, _val, _ip1, _ip2)              \
+do {                                                                          \
+  ikev2_main_t *km = &ikev2_main;                                             \
+  if (PREDICT_FALSE (km->log_level >= _level))                                \
+    {                                                                         \
+      ELOG_TYPE_DECLARE (e) =                                                 \
+        {                                                                     \
+          .format = "ikev2: " _format,                                        \
+          .format_args = "i8i1i1i1i1i1i1i1i1",                                \
+        };                                                                    \
+      CLIB_PACKED(struct {                                                    \
+        u64 val;                                                              \
+        u8 i11; u8 i12; u8 i13; u8 i14;                                       \
+        u8 i21; u8 i22; u8 i23; u8 i24; }) *ed;                               \
+      ed = ELOG_DATA (&vlib_global_main.elog_main, e);                        \
+      ed->val = _val;                                                         \
+      ed->i14 = (_ip1) >> 24;                                                 \
+      ed->i13 = (_ip1) >> 16;                                                 \
+      ed->i12 = (_ip1) >> 8;                                                  \
+      ed->i11 = (_ip1);                                                       \
+      ed->i24 = (_ip2) >> 24;                                                 \
+      ed->i23 = (_ip2) >> 16;                                                 \
+      ed->i22 = (_ip2) >> 8;                                                  \
+      ed->i21 = (_ip2);                                                       \
+    }                                                                         \
+} while (0)
+
+#define ikev2_elog_peers(_level, _format, _ip1, _ip2)                         \
+do {                                                                          \
+  ikev2_main_t *km = &ikev2_main;                                             \
+  if (PREDICT_FALSE (km->log_level >= _level))                                \
+    {                                                                         \
+      ELOG_TYPE_DECLARE (e) =                                                 \
+        {                                                                     \
+          .format = "ikev2: " _format,                                        \
+          .format_args = "i1i1i1i1i1i1i1i1",                                  \
+        };                                                                    \
+      CLIB_PACKED(struct {                                                    \
+        u8 i11; u8 i12; u8 i13; u8 i14;                                       \
+        u8 i21; u8 i22; u8 i23; u8 i24; }) *ed;                               \
+      ed = ELOG_DATA (&vlib_global_main.elog_main, e);                        \
+      ed->i14 = (_ip1) >> 24;                                                 \
+      ed->i13 = (_ip1) >> 16;                                                 \
+      ed->i12 = (_ip1) >> 8;                                                  \
+      ed->i11 = (_ip1);                                                       \
+      ed->i24 = (_ip2) >> 24;                                                 \
+      ed->i23 = (_ip2) >> 16;                                                 \
+      ed->i22 = (_ip2) >> 8;                                                  \
+      ed->i21 = (_ip2);                                                       \
+    }                                                                         \
+} while (0)
+
+#define ikev2_elog_error(_msg) \
+  _ikev2_elog(IKEV2_LOG_ERROR, "[error] " _msg)
+#define ikev2_elog_warning(_msg) \
+  _ikev2_elog(IKEV2_LOG_WARNING, "[warning] " _msg)
+#define ikev2_elog_debug(_msg) \
+  _ikev2_elog(IKEV2_LOG_DEBUG, "[debug] " _msg)
+#define ikev2_elog_detail(_msg) \
+  _ikev2_elog(IKEV2_LOG_DETAIL, "[detail] " _msg)
+
+/* logging for main thread */
+#define ikev2_log_error(...) \
+  vlib_log(VLIB_LOG_LEVEL_ERR, ikev2_main.log_class, __VA_ARGS__)
+#define ikev2_log_warning(...) \
+  vlib_log(VLIB_LOG_LEVEL_WARNING, ikev2_main.log_class, __VA_ARGS__)
+#define ikev2_log_debug(...) \
+  vlib_log(VLIB_LOG_LEVEL_DEBUG, ikev2_main.log_class, __VA_ARGS__)
 
 typedef enum
 {
@@ -302,6 +462,12 @@ typedef struct
 
   /* API message ID base */
   u16 msg_id_base;
+
+  /* log class used for main thread */
+  vlib_log_class_t log_class;
+
+  /* logging level */
+  ikev2_log_level_t log_level;
 } ikev2_main_t;
 
 extern ikev2_main_t ikev2_main;
@@ -361,7 +527,7 @@ ikev2_sa_proposal_t *ikev2_parse_sa_payload (ike_payload_header_t * ikep);
 ikev2_ts_t *ikev2_parse_ts_payload (ike_payload_header_t * ikep);
 ikev2_delete_t *ikev2_parse_delete_payload (ike_payload_header_t * ikep);
 ikev2_notify_t *ikev2_parse_notify_payload (ike_payload_header_t * ikep);
-
+int ikev2_set_log_level (ikev2_log_level_t log_level);
 #endif /* __included_ikev2_priv_h__ */