denozord/strongswan-ext
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

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

Browse Source
This commit is contained in:
Tobias Brunner
2016-06-10 10:34:09 +02:00
parent a0178fe26e
commit 25178f4594
1 changed files with 82 additions and 108 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/libcharon/plugins/kernel_netlink/kernel_netlink_ipsec.c
+82 -108
View File
@@ -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;