kernel-netlink: Consistently print mark in log messages only if set

diff --git a/src/libcharon/plugins/kernel_netlink/kernel_netlink_ipsec.c b/src/libcharon/plugins/kernel_netlink/kernel_netlink_ipsec.c
index fbeff9181428cd7610d7431699c170a9cc46998f..4f7548c49547e53c168f9ffb54dce1ae69f17ee7 100644 (file)
--- a/src/libcharon/plugins/kernel_netlink/kernel_netlink_ipsec.c
+++ b/src/libcharon/plugins/kernel_netlink/kernel_netlink_ipsec.c
@@ -1228,6 +1228,17 @@ METHOD(kernel_ipsec_t, get_cpi, status_t,
        return SUCCESS;
 }
 
+/**
+ * Format the mark for debug messages
+ */
+static void format_mark(char *buf, int buflen, mark_t mark)
+{
+       if (mark.value)
+       {
+               snprintf(buf, buflen, " (mark %u/0x%08x)", mark.value, mark.mask);
+       }
+}
+
 /**
  * Add a XFRM mark to message if required
  */
@@ -1253,7 +1264,7 @@ METHOD(kernel_ipsec_t, add_sa, status_t,
        kernel_ipsec_add_sa_t *data)
 {
        netlink_buf_t request;
-       char *alg_name;
+       char *alg_name, markstr[32] = "";
        struct nlmsghdr *hdr;
        struct xfrm_usersa_info *sa;
        uint16_t icv_size = 64, ipcomp = data->ipcomp;
@@ -1294,10 +1305,10 @@ METHOD(kernel_ipsec_t, add_sa, status_t,
        }
 
        memset(&request, 0, sizeof(request));
+       format_mark(markstr, sizeof(markstr), id->mark);
 
-       DBG2(DBG_KNL, "adding SAD entry with SPI %.8x and reqid {%u}  (mark "
-                "%u/0x%08x)", ntohl(id->spi), data->reqid, id->mark.value,
-                id->mark.mask);
+       DBG2(DBG_KNL, "adding SAD entry with SPI %.8x and reqid {%u}%s",
+                ntohl(id->spi), data->reqid, markstr);
 
        hdr = &request.hdr;
        hdr->nlmsg_flags = NLM_F_REQUEST | NLM_F_ACK;
@@ -1600,17 +1611,8 @@ METHOD(kernel_ipsec_t, add_sa, status_t,
 
        if (this->socket_xfrm->send_ack(this->socket_xfrm, hdr) != SUCCESS)
        {
-               if (id->mark.value)
-               {
-                       DBG1(DBG_KNL, "unable to add SAD entry with SPI %.8x  (mark "
-                                "%u/0x%08x)", ntohl(id->spi), id->mark.value,
-                                id->mark.mask);
-               }
-               else
-               {
-                       DBG1(DBG_KNL, "unable to add SAD entry with SPI %.8x",
-                                ntohl(id->spi));
-               }
+               DBG1(DBG_KNL, "unable to add SAD entry with SPI %.8x%s", ntohl(id->spi),
+                        markstr);
                goto failed;
        }
 
@@ -1737,11 +1739,13 @@ METHOD(kernel_ipsec_t, query_sa, status_t,
        struct xfrm_usersa_info *sa = NULL;
        status_t status = FAILED;
        size_t len;
+       char markstr[32] = "";
 
        memset(&request, 0, sizeof(request));
+       format_mark(markstr, sizeof(markstr), id->mark);
 
-       DBG2(DBG_KNL, "querying SAD entry with SPI %.8x  (mark %u/0x%08x)",
-                ntohl(id->spi), id->mark.value, id->mark.mask);
+       DBG2(DBG_KNL, "querying SAD entry with SPI %.8x%s", ntohl(id->spi),
+                markstr);
 
        hdr = &request.hdr;
        hdr->nlmsg_flags = NLM_F_REQUEST;
@@ -1775,19 +1779,9 @@ METHOD(kernel_ipsec_t, query_sa, status_t,
                                {
                                        struct nlmsgerr *err = NLMSG_DATA(hdr);
 
-                                       if (id->mark.value)
-                                       {
-                                               DBG1(DBG_KNL, "querying SAD entry with SPI %.8x  (mark "
-                                                        "%u/0x%08x) failed: %s (%d)", ntohl(id->spi),
-                                                        id->mark.value, id->mark.mask,
-                                                        strerror(-err->error), -err->error);
-                                       }
-                                       else
-                                       {
-                                               DBG1(DBG_KNL, "querying SAD entry with SPI %.8x "
-                                                        "failed: %s (%d)", ntohl(id->spi),
-                                                        strerror(-err->error), -err->error);
-                                       }
+                                       DBG1(DBG_KNL, "querying SAD entry with SPI %.8x%s failed: "
+                                                "%s (%d)", ntohl(id->spi), markstr,
+                                                strerror(-err->error), -err->error);
                                        break;
                                }
                                default:
@@ -1802,8 +1796,8 @@ METHOD(kernel_ipsec_t, query_sa, status_t,
 
        if (sa == NULL)
        {
-               DBG2(DBG_KNL, "unable to query SAD entry with SPI %.8x",
-                        ntohl(id->spi));
+               DBG2(DBG_KNL, "unable to query SAD entry with SPI %.8x%s",
+                        ntohl(id->spi), markstr);
        }
        else
        {
@@ -1835,6 +1829,7 @@ METHOD(kernel_ipsec_t, del_sa, status_t,
        netlink_buf_t request;
        struct nlmsghdr *hdr;
        struct xfrm_usersa_id *sa_id;
+       char markstr[32] = "";
 
        /* if IPComp was used, we first delete the additional IPComp SA */
        if (data->cpi)
@@ -1851,9 +1846,10 @@ METHOD(kernel_ipsec_t, del_sa, status_t,
        }
 
        memset(&request, 0, sizeof(request));
+       format_mark(markstr, sizeof(markstr), id->mark);
 
-       DBG2(DBG_KNL, "deleting SAD entry with SPI %.8x  (mark %u/0x%08x)",
-                ntohl(id->spi), id->mark.value, id->mark.mask);
+       DBG2(DBG_KNL, "deleting SAD entry with SPI %.8x%s", ntohl(id->spi),
+                markstr);
 
        hdr = &request.hdr;
        hdr->nlmsg_flags = NLM_F_REQUEST | NLM_F_ACK;
@@ -1874,23 +1870,14 @@ METHOD(kernel_ipsec_t, del_sa, status_t,
        switch (this->socket_xfrm->send_ack(this->socket_xfrm, hdr))
        {
                case SUCCESS:
-                       DBG2(DBG_KNL, "deleted SAD entry with SPI %.8x  (mark %u/0x%08x)",
-                                ntohl(id->spi), id->mark.value, id->mark.mask);
+                       DBG2(DBG_KNL, "deleted SAD entry with SPI %.8x%s",
+                                ntohl(id->spi), markstr);
                        return SUCCESS;
                case NOT_FOUND:
                        return NOT_FOUND;
                default:
-                       if (id->mark.value)
-                       {
-                               DBG1(DBG_KNL, "unable to delete SAD entry with SPI %.8x  (mark "
-                                        "%u/0x%08x)", ntohl(id->spi), id->mark.value,
-                                        id->mark.mask);
-                       }
-                       else
-                       {
-                               DBG1(DBG_KNL, "unable to delete SAD entry with SPI %.8x",
-                                        ntohl(id->spi));
-                       }
+                       DBG1(DBG_KNL, "unable to delete SAD entry with SPI %.8x%s",
+                                ntohl(id->spi), markstr);
                        return FAILED;
        }
 }
@@ -1913,6 +1900,7 @@ METHOD(kernel_ipsec_t, update_sa, status_t,
        uint32_t replay_esn_len = 0;
        kernel_ipsec_del_sa_t del = { 0 };
        status_t status = FAILED;
+       char markstr[32] = "";
 
        /* if IPComp is used, we first update the IPComp SA */
        if (data->cpi)
@@ -1932,9 +1920,10 @@ METHOD(kernel_ipsec_t, update_sa, status_t,
        }
 
        memset(&request, 0, sizeof(request));
+       format_mark(markstr, sizeof(markstr), id->mark);
 
-       DBG2(DBG_KNL, "querying SAD entry with SPI %.8x for update",
-                ntohl(id->spi));
+       DBG2(DBG_KNL, "querying SAD entry with SPI %.8x%s for update",
+                ntohl(id->spi), markstr);
 
        /* query the existing SA first */
        hdr = &request.hdr;
@@ -1983,8 +1972,8 @@ METHOD(kernel_ipsec_t, update_sa, status_t,
        }
        if (out_sa == NULL)
        {
-               DBG1(DBG_KNL, "unable to update SAD entry with SPI %.8x",
-                        ntohl(id->spi));
+               DBG1(DBG_KNL, "unable to update SAD entry with SPI %.8x%s",
+                        ntohl(id->spi), markstr);
                goto failed;
        }
 
@@ -1994,13 +1983,13 @@ METHOD(kernel_ipsec_t, update_sa, status_t,
        /* delete the old SA (without affecting the IPComp SA) */
        if (del_sa(this, id, &del) != SUCCESS)
        {
-               DBG1(DBG_KNL, "unable to delete old SAD entry with SPI %.8x",
-                        ntohl(id->spi));
+               DBG1(DBG_KNL, "unable to delete old SAD entry with SPI %.8x%s",
+                        ntohl(id->spi), markstr);
                goto failed;
        }
 
-       DBG2(DBG_KNL, "updating SAD entry with SPI %.8x from %#H..%#H to %#H..%#H",
-                ntohl(id->spi), id->src, id->dst, data->new_src,
+       DBG2(DBG_KNL, "updating SAD entry with SPI %.8x%s from %#H..%#H to "
+                "%#H..%#H", ntohl(id->spi), markstr, id->src, id->dst, data->new_src,
                 data->new_dst);
        /* copy over the SA from out to request */
        hdr = &request.hdr;
@@ -2080,7 +2069,7 @@ METHOD(kernel_ipsec_t, update_sa, status_t,
        else
        {
                DBG1(DBG_KNL, "unable to copy replay state from old SAD entry with "
-                        "SPI %.8x", ntohl(id->spi));
+                        "SPI %.8x%s", ntohl(id->spi), markstr);
        }
        if (lifetime)
        {
@@ -2097,13 +2086,13 @@ METHOD(kernel_ipsec_t, update_sa, status_t,
        else
        {
                DBG1(DBG_KNL, "unable to copy usage stats from old SAD entry with "
-                        "SPI %.8x", ntohl(id->spi));
+                        "SPI %.8x%s", ntohl(id->spi), markstr);
        }
 
        if (this->socket_xfrm->send_ack(this->socket_xfrm, hdr) != SUCCESS)
        {
-               DBG1(DBG_KNL, "unable to update SAD entry with SPI %.8x",
-                        ntohl(id->spi));
+               DBG1(DBG_KNL, "unable to update SAD entry with SPI %.8x%s",
+                        ntohl(id->spi), markstr);
                goto failed;
        }
 
@@ -2403,6 +2392,7 @@ METHOD(kernel_ipsec_t, add_policy, status_t,
        policy_sa_t *assigned_sa, *current_sa;
        enumerator_t *enumerator;
        bool found = FALSE, update = TRUE;
+       char markstr[32] = "";
 
        /* create a policy */
        INIT(policy,
@@ -2411,6 +2401,7 @@ METHOD(kernel_ipsec_t, add_policy, status_t,
                .direction = id->dir,
                .reqid = data->sa->reqid,
        );
+       format_mark(markstr, sizeof(markstr), id->mark);
 
        /* find the policy, which matches EXACTLY */
        this->mutex->lock(this->mutex);
@@ -2420,18 +2411,18 @@ METHOD(kernel_ipsec_t, add_policy, status_t,
                if (current->reqid && data->sa->reqid &&
                        current->reqid != data->sa->reqid)
                {
-                       DBG1(DBG_CFG, "unable to install policy %R === %R %N (mark "
-                                "%u/0x%08x) for reqid %u, the same policy for reqid %u exists",
-                                id->src_ts, id->dst_ts, policy_dir_names, id->dir,
-                                id->mark.value, id->mark.mask, data->sa->reqid, current->reqid);
+                       DBG1(DBG_CFG, "unable to install policy %R === %R %N%s for reqid "
+                                "%u, the same policy for reqid %u exists",
+                                id->src_ts, id->dst_ts, policy_dir_names, id->dir, markstr,
+                                data->sa->reqid, current->reqid);
                        policy_entry_destroy(this, policy);
                        this->mutex->unlock(this->mutex);
                        return INVALID_STATE;
                }
                /* use existing policy */
-               DBG2(DBG_KNL, "policy %R === %R %N  (mark %u/0x%08x) already exists, "
-                       "increasing refcount", id->src_ts, id->dst_ts, policy_dir_names,
-                       id->dir, id->mark.value, id->mark.mask);
+               DBG2(DBG_KNL, "policy %R === %R %N%s already exists, increasing "
+                        "refcount", id->src_ts, id->dst_ts, policy_dir_names, id->dir,
+                        markstr);
                policy_entry_destroy(this, policy);
                policy = current;
                found = TRUE;
@@ -2489,15 +2480,14 @@ METHOD(kernel_ipsec_t, add_policy, status_t,
                found = TRUE;
        }
 
-       DBG2(DBG_KNL, "%s policy %R === %R %N  (mark %u/0x%08x)",
-                found ? "updating" : "adding", id->src_ts, id->dst_ts,
-                policy_dir_names, id->dir, id->mark.value, id->mark.mask);
+       DBG2(DBG_KNL, "%s policy %R === %R %N%s", found ? "updating" : "adding",
+                id->src_ts, id->dst_ts, policy_dir_names, id->dir, markstr);
 
        if (add_policy_internal(this, policy, assigned_sa, found) != SUCCESS)
        {
-               DBG1(DBG_KNL, "unable to %s policy %R === %R %N",
+               DBG1(DBG_KNL, "unable to %s policy %R === %R %N%s",
                         found ? "update" : "add", id->src_ts, id->dst_ts,
-                        policy_dir_names, id->dir);
+                        policy_dir_names, id->dir, markstr);
                return FAILED;
        }
        return SUCCESS;
@@ -2512,12 +2502,13 @@ METHOD(kernel_ipsec_t, query_policy, status_t,
        struct xfrm_userpolicy_id *policy_id;
        struct xfrm_userpolicy_info *policy = NULL;
        size_t len;
+       char markstr[32] = "";
 
        memset(&request, 0, sizeof(request));
+       format_mark(markstr, sizeof(markstr), id->mark);
 
-       DBG2(DBG_KNL, "querying policy %R === %R %N  (mark %u/0x%08x)",
-                id->src_ts, id->dst_ts, policy_dir_names, id->dir, id->mark.value,
-                id->mark.mask);
+       DBG2(DBG_KNL, "querying policy %R === %R %N%s", id->src_ts, id->dst_ts,
+                policy_dir_names, id->dir, markstr);
 
        hdr = &request.hdr;
        hdr->nlmsg_flags = NLM_F_REQUEST;
@@ -2564,8 +2555,8 @@ METHOD(kernel_ipsec_t, query_policy, status_t,
 
        if (policy == NULL)
        {
-               DBG2(DBG_KNL, "unable to query policy %R === %R %N", id->src_ts,
-                        id->dst_ts, policy_dir_names, id->dir);
+               DBG2(DBG_KNL, "unable to query policy %R === %R %N%s", id->src_ts,
+                        id->dst_ts, policy_dir_names, id->dir, markstr);
                free(out);
                return FAILED;
        }
@@ -2602,10 +2593,12 @@ METHOD(kernel_ipsec_t, del_policy, status_t,
                .mark = id->mark,
                .cfg = *data->sa,
        };
+       char markstr[32] = "";
 
-       DBG2(DBG_KNL, "deleting policy %R === %R %N  (mark %u/0x%08x)",
-                id->src_ts, id->dst_ts, policy_dir_names, id->dir, id->mark.value,
-                id->mark.mask);
+       format_mark(markstr, sizeof(markstr), id->mark);
+
+       DBG2(DBG_KNL, "deleting policy %R === %R %N%s", id->src_ts, id->dst_ts,
+                policy_dir_names, id->dir, markstr);
 
        /* create a policy */
        memset(&policy, 0, sizeof(policy_entry_t));
@@ -2618,17 +2611,8 @@ METHOD(kernel_ipsec_t, del_policy, status_t,
        current = this->policies->get(this->policies, &policy);
        if (!current)
        {
-               if (id->mark.value)
-               {
-                       DBG1(DBG_KNL, "deleting policy %R === %R %N  (mark %u/0x%08x) "
-                                "failed, not found", id->src_ts, id->dst_ts,
-                                policy_dir_names, id->dir, id->mark.value, id->mark.mask);
-               }
-               else
-               {
-                       DBG1(DBG_KNL, "deleting policy %R === %R %N failed, not found",
-                                id->src_ts, id->dst_ts, policy_dir_names, id->dir);
-               }
+               DBG1(DBG_KNL, "deleting policy %R === %R %N%s failed, not found",
+                        id->src_ts, id->dst_ts, policy_dir_names, id->dir, markstr);
                this->mutex->unlock(this->mutex);
                return NOT_FOUND;
        }
@@ -2664,15 +2648,14 @@ METHOD(kernel_ipsec_t, del_policy, status_t,
                        return SUCCESS;
                }
 
-               DBG2(DBG_KNL, "updating policy %R === %R %N  (mark %u/0x%08x)",
-                        id->src_ts, id->dst_ts, policy_dir_names, id->dir, id->mark.value,
-                        id->mark.mask);
+               DBG2(DBG_KNL, "updating policy %R === %R %N%s", id->src_ts, id->dst_ts,
+                        policy_dir_names, id->dir, markstr);
 
                current->used_by->get_first(current->used_by, (void**)&mapping);
                if (add_policy_internal(this, current, mapping, TRUE) != SUCCESS)
                {
-                       DBG1(DBG_KNL, "unable to update policy %R === %R %N",
-                                id->src_ts, id->dst_ts, policy_dir_names, id->dir);
+                       DBG1(DBG_KNL, "unable to update policy %R === %R %N%s",
+                                id->src_ts, id->dst_ts, policy_dir_names, id->dir, markstr);
                        return FAILED;
                }
                return SUCCESS;
@@ -2703,8 +2686,8 @@ METHOD(kernel_ipsec_t, del_policy, status_t,
                                                                          route->src_ip, route->if_name) != SUCCESS)
                {
                        DBG1(DBG_KNL, "error uninstalling route installed with policy "
-                                "%R === %R %N", id->src_ts, id->dst_ts, policy_dir_names,
-                                id->dir);
+                                "%R === %R %N%s", id->src_ts, id->dst_ts, policy_dir_names,
+                                id->dir, markstr);
                }
        }
 
@@ -2714,17 +2697,8 @@ METHOD(kernel_ipsec_t, del_policy, status_t,
 
        if (this->socket_xfrm->send_ack(this->socket_xfrm, hdr) != SUCCESS)
        {
-               if (id->mark.value)
-               {
-                       DBG1(DBG_KNL, "unable to delete policy %R === %R %N  (mark "
-                                "%u/0x%08x)", id->src_ts, id->dst_ts, policy_dir_names,
-                                id->dir, id->mark.value, id->mark.mask);
-               }
-               else
-               {
-                       DBG1(DBG_KNL, "unable to delete policy %R === %R %N",
-                                id->src_ts, id->dst_ts, policy_dir_names, id->dir);
-               }
+               DBG1(DBG_KNL, "unable to delete policy %R === %R %N%s", id->src_ts,
+                        id->dst_ts, policy_dir_names, id->dir, markstr);
                return FAILED;
        }
        return SUCCESS;