summaryrefslogtreecommitdiff
path: root/src
diff options
context:
space:
mode:
authorDimitri Staessens <dimitri@ouroboros.rocks>2023-08-30 16:07:03 +0200
committerSander Vrijders <sander@ouroboros.rocks>2023-08-30 17:12:41 +0200
commitde2b10441c7835d4221dea3b4414478f72c549f6 (patch)
treeead66900f5d6dcd7ecc5b61f97b11a75d10cd123 /src
parent3a321cc77e0f6d29167a925dd706fc36e5aa7cdd (diff)
downloadouroboros-de2b10441c7835d4221dea3b4414478f72c549f6.tar.gz
ouroboros-de2b10441c7835d4221dea3b4414478f72c549f6.zip
ipcpd: Revise logging
This revises the logging in the IPCPs to be a more consistent and reduce duplicate messages in nested functions. Signed-off-by: Dimitri Staessens <dimitri@ouroboros.rocks> Signed-off-by: Sander Vrijders <sander@ouroboros.rocks>
Diffstat (limited to 'src')
-rw-r--r--src/ipcpd/broadcast/dt.c21
-rw-r--r--src/ipcpd/broadcast/main.c9
-rw-r--r--src/ipcpd/common/connmgr.c127
-rw-r--r--src/ipcpd/common/enroll.c4
-rw-r--r--src/ipcpd/eth/eth.c78
-rw-r--r--src/ipcpd/ipcp.c214
-rw-r--r--src/ipcpd/local/main.c11
-rw-r--r--src/ipcpd/shim-data.c4
-rw-r--r--src/ipcpd/udp/main.c60
-rw-r--r--src/ipcpd/unicast/dt.c23
-rw-r--r--src/ipcpd/unicast/fa.c30
-rw-r--r--src/ipcpd/unicast/main.c4
-rw-r--r--src/ipcpd/unicast/pff.c4
13 files changed, 344 insertions, 245 deletions
diff --git a/src/ipcpd/broadcast/dt.c b/src/ipcpd/broadcast/dt.c
index db184e89..935ac384 100644
--- a/src/ipcpd/broadcast/dt.c
+++ b/src/ipcpd/broadcast/dt.c
@@ -78,15 +78,16 @@ static int dt_add_nb(int fd)
list_for_each(p, &fwd.nbs) {
struct nb * el = list_entry(p, struct nb, next);
if (el->fd == fd) {
- log_dbg("Already know neighbor.");
pthread_rwlock_unlock(&fwd.nbs_lock);
- return -EPERM;
+ log_warn("Already know neighbor on fd %d.", fd);
+ return 0;
}
}
nb = malloc(sizeof(*nb));
if (nb == NULL) {
pthread_rwlock_unlock(&fwd.nbs_lock);
+ log_err("Failed to malloc neighbor struct.");
return -ENOMEM;
}
@@ -96,10 +97,10 @@ static int dt_add_nb(int fd)
++fwd.nbs_len;
- log_dbg("Neighbor %d added.", fd);
-
pthread_rwlock_unlock(&fwd.nbs_lock);
+ log_dbg("Neighbor %d added.", fd);
+
return 0;
}
@@ -124,6 +125,8 @@ static int dt_del_nb(int fd)
pthread_rwlock_unlock(&fwd.nbs_lock);
+ log_err("Neighbor not found on fd %d.", fd);
+
return -EPERM;
}
@@ -191,7 +194,7 @@ static void * dt_reader(void * o)
while (true) {
ret = fevent(fwd.set, fq, NULL);
if (ret < 0) {
- log_warn("Event error: %d.", ret);
+ log_warn("Event warning: %d.", ret);
continue;
}
@@ -226,13 +229,13 @@ static void handle_event(void * self,
switch (event) {
case NOTIFY_DT_CONN_ADD:
- if (dt_add_nb(c->flow_info.fd))
- log_dbg("Failed to add neighbor.");
+ if (dt_add_nb(c->flow_info.fd) < 0)
+ log_err("Failed to add neighbor.");
fset_add(fwd.set, c->flow_info.fd);
break;
case NOTIFY_DT_CONN_DEL:
- if (dt_del_nb(c->flow_info.fd))
- log_dbg("Failed to delete neighbor.");
+ if (dt_del_nb(c->flow_info.fd) < 0)
+ log_err("Failed to delete neighbor.");
fset_del(fwd.set, c->flow_info.fd);
break;
default:
diff --git a/src/ipcpd/broadcast/main.c b/src/ipcpd/broadcast/main.c
index b0cbc6a7..de1feeb2 100644
--- a/src/ipcpd/broadcast/main.c
+++ b/src/ipcpd/broadcast/main.c
@@ -146,7 +146,6 @@ static int broadcast_ipcp_enroll(const char * dst,
log_info_id(id, "Enrolled with %s.", dst);
-
info->dir_hash_algo = ipcpi.dir_hash_algo;
strcpy(info->layer_name, ipcpi.layer_name);
@@ -178,8 +177,6 @@ static int broadcast_ipcp_bootstrap(const struct ipcp_config * conf)
goto fail_start;
}
- log_dbg("Bootstrapped in layer %s.", conf->layer_info.layer_name);
-
return 0;
fail_start:
@@ -221,8 +218,10 @@ static int broadcast_ipcp_join(int fd,
conn.flow_info.fd = fd;
- if (name_check(dst) != 0)
+ if (name_check(dst) != 0) {
+ log_err("Failed to check name.");
return -1;
+ }
notifier_event(NOTIFY_DT_CONN_ADD, &conn);
@@ -264,7 +263,7 @@ int main(int argc,
char * argv[])
{
if (ipcp_init(argc, argv, &broadcast_ops, THIS_TYPE) < 0) {
- log_err("Failed to init IPCP.");
+ log_err("Failed to initialize IPCP.");
goto fail_init;
}
diff --git a/src/ipcpd/common/connmgr.c b/src/ipcpd/common/connmgr.c
index 6ee41384..408d7de6 100644
--- a/src/ipcpd/common/connmgr.c
+++ b/src/ipcpd/common/connmgr.c
@@ -143,38 +143,43 @@ static void * flow_acceptor(void * o)
fd = flow_accept(&qs, NULL);
if (fd < 0) {
if (fd != -EIRMD)
- log_warn("Flow accept failed: %d", fd);
+ log_err("Flow accept failed: %d", fd);
continue;
}
+ log_info("Handling incoming flow %d",fd);
+
if (cacep_rcv(fd, &rcv_info)) {
- log_dbg("Error establishing application connection.");
+ log_err("Error receiving CACEP info.");
flow_dealloc(fd);
continue;
}
+ log_info("Request to connect to %s.", rcv_info.comp_name);
+
id = get_id_by_name(rcv_info.comp_name);
if (id < 0) {
- log_dbg("Connection request for unknown component %s.",
+ log_err("Connection request for unknown component %s.",
rcv_info.comp_name);
cacep_snd(fd, &fail_info);
flow_dealloc(fd);
continue;
}
- assert(id < COMPID_MAX);
-
if (cacep_snd(fd, &connmgr.comps[id].info)) {
- log_dbg("Failed to respond to request.");
+ log_err("Failed to respond to CACEP request.");
flow_dealloc(fd);
continue;
}
if (add_comp_conn(id, fd, qs, &rcv_info)) {
- log_dbg("Failed to add new connection.");
+ log_err("Failed to add new connection.");
flow_dealloc(fd);
continue;
}
+
+ log_info("Finished handling incoming flow %d for %s: 0.",
+ fd, rcv_info.comp_name);
}
return (void *) 0;
@@ -215,8 +220,10 @@ int connmgr_init(void)
{
connmgr.state = CONNMGR_INIT;
- if (notifier_reg(handle_event, NULL))
+ if (notifier_reg(handle_event, NULL)) {
+ log_err("Failed to register notifier.");
return -1;
+ }
return 0;
}
@@ -236,8 +243,10 @@ void connmgr_fini(void)
int connmgr_start(void)
{
- if (pthread_create(&connmgr.acceptor, NULL, flow_acceptor, NULL))
+ if (pthread_create(&connmgr.acceptor, NULL, flow_acceptor, NULL)) {
+ log_err("Failed to create pthread: %s.", strerror(errno));
return -1;
+ }
connmgr.state = CONNMGR_RUNNING;
@@ -259,12 +268,14 @@ int connmgr_comp_init(enum comp_id id,
comp = connmgr.comps + id;
- if (pthread_mutex_init(&comp->lock, NULL))
- return -1;
+ if (pthread_mutex_init(&comp->lock, NULL)) {
+ log_err("Failed to initialize mutex: %s.", strerror(errno));
+ goto fail_mutex;
+ }
if (pthread_cond_init(&comp->cond, NULL)) {
- pthread_mutex_destroy(&comp->lock);
- return -1;
+ log_err("Failed to initialize condvar: %s.", strerror(errno));
+ goto fail_cond;
}
list_head_init(&comp->conns);
@@ -273,6 +284,11 @@ int connmgr_comp_init(enum comp_id id,
memcpy(&connmgr.comps[id].info, info, sizeof(connmgr.comps[id].info));
return 0;
+
+ fail_cond:
+ pthread_mutex_destroy(&comp->lock);
+ fail_mutex:
+ return -1;
}
void connmgr_comp_fini(enum comp_id id)
@@ -322,20 +338,19 @@ int connmgr_ipcp_connect(const char * dst,
ce = malloc(sizeof(*ce));
if (ce == NULL) {
- log_dbg("Out of memory.");
- return -1;
+ log_err("Out of memory.");
+ goto fail_malloc;
}
id = get_id_by_name(component);
if (id < 0) {
- log_dbg("No such component: %s", component);
- free(ce);
- return -1;
+ log_err("No such component: %s", component);
+ goto fail_id;
}
if (connmgr_alloc(id, dst, &qs, &ce->conn)) {
- free(ce);
- return -1;
+ log_err("Failed to allocate flow.");
+ goto fail_id;
}
if (strlen(dst) > DST_MAX_STRLEN) {
@@ -353,6 +368,11 @@ int connmgr_ipcp_connect(const char * dst,
pthread_mutex_unlock(&connmgr.comps[id].lock);
return 0;
+
+ fail_id:
+ free(ce);
+ fail_malloc:
+ return -1;
}
int connmgr_ipcp_disconnect(const char * dst,
@@ -366,8 +386,10 @@ int connmgr_ipcp_disconnect(const char * dst,
assert(component);
id = get_id_by_name(component);
- if (id < 0)
+ if (id < 0) {
+ log_err("No such component: %s.", component);
return -1;
+ }
pthread_mutex_lock(&connmgr.comps[id].lock);
@@ -393,54 +415,55 @@ int connmgr_alloc(enum comp_id id,
qosspec_t * qs,
struct conn * conn)
{
+ struct comp * comp;
+ int fd;
+
assert(id >= 0 && id < COMPID_MAX);
assert(dst);
- conn->flow_info.fd = flow_alloc(dst, qs, NULL);
- if (conn->flow_info.fd < 0) {
- log_dbg("Failed to allocate flow to %s.", dst);
- return -1;
+ comp = connmgr.comps + id;
+
+ fd = flow_alloc(dst, qs, NULL);
+ if (fd < 0) {
+ log_err("Failed to allocate flow to %s.", dst);
+ goto fail_alloc;
}
+ conn->flow_info.fd = fd;
+
if (qs != NULL)
conn->flow_info.qs = *qs;
else
memset(&conn->flow_info.qs, 0, sizeof(conn->flow_info.qs));
log_dbg("Sending cacep info for protocol %s to fd %d.",
- connmgr.comps[id].info.protocol, conn->flow_info.fd);
+ comp->info.protocol, conn->flow_info.fd);
- if (cacep_snd(conn->flow_info.fd, &connmgr.comps[id].info)) {
- log_dbg("Failed to create application connection.");
- flow_dealloc(conn->flow_info.fd);
- return -1;
+ if (cacep_snd(fd, &comp->info)) {
+ log_err("Failed to send CACEP info.");
+ goto fail_cacep;
}
- if (cacep_rcv(conn->flow_info.fd, &conn->conn_info)) {
- log_dbg("Failed to connect to application.");
- flow_dealloc(conn->flow_info.fd);
- return -1;
+ if (cacep_rcv(fd, &conn->conn_info)) {
+ log_err("Failed to receive CACEP info.");
+ goto fail_cacep;
}
- if (strcmp(connmgr.comps[id].info.protocol, conn->conn_info.protocol)) {
- log_dbg("Unknown protocol (requested %s, got %s).",
- connmgr.comps[id].info.protocol,
- conn->conn_info.protocol);
- flow_dealloc(conn->flow_info.fd);
- return -1;
+ if (strcmp(comp->info.protocol, conn->conn_info.protocol)) {
+ log_err("Unknown protocol (requested %s, got %s).",
+ comp->info.protocol, conn->conn_info.protocol);
+ goto fail_cacep;
}
- if (connmgr.comps[id].info.pref_version !=
- conn->conn_info.pref_version) {
- log_dbg("Unknown protocol version.");
- flow_dealloc(conn->flow_info.fd);
- return -1;
+ if (comp->info.pref_version != conn->conn_info.pref_version) {
+ log_err("Unknown protocol version %d.",
+ conn->conn_info.pref_version);
+ goto fail_cacep;
}
- if (connmgr.comps[id].info.pref_syntax != conn->conn_info.pref_syntax) {
- log_dbg("Unknown protocol syntax.");
- flow_dealloc(conn->flow_info.fd);
- return -1;
+ if (comp->info.pref_syntax != conn->conn_info.pref_syntax) {
+ log_err("Unknown protocol syntax.");
+ goto fail_cacep;
}
switch (id) {
@@ -458,6 +481,11 @@ int connmgr_alloc(enum comp_id id,
}
return 0;
+
+ fail_cacep:
+ flow_dealloc(conn->flow_info.fd);
+ fail_alloc:
+ return -1;
}
int connmgr_dealloc(enum comp_id id,
@@ -503,6 +531,7 @@ int connmgr_wait(enum comp_id id,
el = list_first_entry((&comp->pending), struct conn_el, next);
if (el == NULL) {
pthread_mutex_unlock(&comp->lock);
+ log_err("Failed to get connection element.");
return -1;
}
diff --git a/src/ipcpd/common/enroll.c b/src/ipcpd/common/enroll.c
index eeff391a..033ae23c 100644
--- a/src/ipcpd/common/enroll.c
+++ b/src/ipcpd/common/enroll.c
@@ -94,7 +94,7 @@ static void * enroll_handle(void * o)
len = flow_read(fd, buf.data, buf.len);
if (len < 0) {
- log_warn("Failed to read from flow %d.", fd);
+ log_err("Failed to read from flow %d.", fd);
goto finish_flow;
}
@@ -102,7 +102,7 @@ static void * enroll_handle(void * o)
msg.len = (size_t) len;
if (enroll_req_des(&req, msg) < 0) {
- log_warn("Failed to unpack request message.");
+ log_err("Failed to unpack request message.");
goto finish_flow;
}
diff --git a/src/ipcpd/eth/eth.c b/src/ipcpd/eth/eth.c
index ef64c07e..3b357067 100644
--- a/src/ipcpd/eth/eth.c
+++ b/src/ipcpd/eth/eth.c
@@ -649,11 +649,12 @@ static int eth_ipcp_alloc_reply(uint8_t * r_addr,
#elif defined(BUILD_ETH_LLC)
log_dbg("Flow reply, fd %d, SSAP %d, DSAP %d.", fd, ssap, dsap);
#endif
- if ((ret = ipcp_flow_alloc_reply(fd, response, mpl, data, len)) < 0)
+ if ((ret = ipcp_flow_alloc_reply(fd, response, mpl, data, len)) < 0) {
+ log_err("Failed to reply to flow allocation.");
return -1;
+ }
return ret;
-
}
static int eth_ipcp_name_query_req(const uint8_t * hash,
@@ -856,7 +857,7 @@ static void * eth_ipcp_packet_reader(void * o)
buf = nm_nextpkt(eth_data.nmd, &hdr);
if (buf == NULL) {
- log_err("Bad read from netmap device.");
+ log_dbg("Bad read from netmap device.");
continue;
}
#else
@@ -887,6 +888,7 @@ static void * eth_ipcp_packet_reader(void * o)
ETH_MTU + ETH_HEADER_TOT_SIZE, 0);
#endif
if (frame_len <= 0) {
+ log_dbg("Failed to receive frame.");
ipcp_sdb_release(sdb);
continue;
}
@@ -939,10 +941,8 @@ static void * eth_ipcp_packet_reader(void * o)
#endif
frame = malloc(sizeof(*frame));
if (frame == NULL) {
-#ifndef HAVE_NETMAP
- ipcp_sdb_release(sdb);
-#endif
- continue;
+ log_err("Failed to allocate frame.");
+ goto fail_frame;
}
memcpy(frame->buf, &e_frame->payload, length);
@@ -954,9 +954,6 @@ static void * eth_ipcp_packet_reader(void * o)
pthread_cond_signal(&eth_data.mgmt_cond);
pthread_mutex_unlock(&eth_data.mgmt_lock);
-#ifndef HAVE_NETMAP
- ipcp_sdb_release(sdb);
-#endif
} else {
pthread_rwlock_rdlock(&eth_data.flows_lock);
@@ -967,10 +964,7 @@ static void * eth_ipcp_packet_reader(void * o)
#endif
if (fd < 0) {
pthread_rwlock_unlock(&eth_data.flows_lock);
-#ifndef HAVE_NETMAP
- ipcp_sdb_release(sdb);
-#endif
- continue;
+ goto fail_frame;
}
#ifdef BUILD_ETH_LLC
@@ -978,10 +972,7 @@ static void * eth_ipcp_packet_reader(void * o)
|| memcmp(eth_data.fd_to_ef[fd].r_addr,
e_frame->src_hwaddr, MAC_SIZE)) {
pthread_rwlock_unlock(&eth_data.flows_lock);
-#ifndef HAVE_NETMAP
- ipcp_sdb_release(sdb);
-#endif
- continue;
+ goto fail_frame;
}
#endif
pthread_rwlock_unlock(&eth_data.flows_lock);
@@ -998,6 +989,12 @@ static void * eth_ipcp_packet_reader(void * o)
#endif
if (np1_flow_write(fd, sdb) < 0)
ipcp_sdb_release(sdb);
+
+ continue;
+ fail_frame:
+#ifndef HAVE_NETMAP
+ ipcp_sdb_release(sdb);
+#endif
}
}
@@ -1455,7 +1452,8 @@ static int eth_ipcp_bootstrap(const struct ipcp_config * conf)
NULL,
eth_ipcp_if_monitor,
NULL)) {
- ipcp_set_state(IPCP_INIT);
+ log_err("Failed to create monitor thread: %s.",
+ strerror(errno));
goto fail_device;
}
#endif
@@ -1464,7 +1462,8 @@ static int eth_ipcp_bootstrap(const struct ipcp_config * conf)
NULL,
eth_ipcp_mgmt_handler,
NULL)) {
- ipcp_set_state(IPCP_INIT);
+ log_err("Failed to create mgmt handler thread: %s.",
+ strerror(errno));
goto fail_mgmt_handler;
}
@@ -1473,7 +1472,8 @@ static int eth_ipcp_bootstrap(const struct ipcp_config * conf)
NULL,
eth_ipcp_packet_reader,
NULL)) {
- ipcp_set_state(IPCP_INIT);
+ log_err("Failed to create packet reader thread: %s",
+ strerror(errno));
goto fail_packet_reader;
}
}
@@ -1483,7 +1483,8 @@ static int eth_ipcp_bootstrap(const struct ipcp_config * conf)
NULL,
eth_ipcp_packet_writer,
NULL)) {
- ipcp_set_state(IPCP_INIT);
+ log_err("Failed to create packet writer thread: %s",
+ strerror(errno));
goto fail_packet_writer;
}
}
@@ -1537,8 +1538,6 @@ static int eth_ipcp_reg(const uint8_t * hash)
return -1;
}
- log_dbg("Registered " HASH_FMT32 ".", HASH_VAL32(hash));
-
return 0;
}
@@ -1617,12 +1616,11 @@ static int eth_ipcp_flow_alloc(int fd,
uint8_t r_addr[MAC_SIZE];
uint64_t addr = 0;
- log_dbg("Allocating flow to " HASH_FMT32 ".", HASH_VAL32(hash));
-
assert(hash);
if (!shim_data_dir_has(eth_data.shim_data, hash)) {
- log_err("Destination unreachable.");
+ log_err("Destination "HASH_FMT32 "unreachable.",
+ HASH_VAL32(hash));
return -1;
}
addr = shim_data_dir_get_addr(eth_data.shim_data, hash);
@@ -1632,6 +1630,7 @@ static int eth_ipcp_flow_alloc(int fd,
ssap = bmp_allocate(eth_data.saps);
if (!bmp_is_id_valid(eth_data.saps, ssap)) {
pthread_rwlock_unlock(&eth_data.flows_lock);
+ log_err("Failed to allocate SSAP.");
return -1;
}
@@ -1658,15 +1657,14 @@ static int eth_ipcp_flow_alloc(int fd,
eth_data.fd_to_ef[fd].sap = -1;
eth_data.ef_to_fd[ssap] = -1;
pthread_rwlock_unlock(&eth_data.flows_lock);
+ log_err("Failed to allocate with peer.");
#endif
return -1;
}
fset_add(eth_data.np1_flows, fd);
-#if defined(BUILD_ETH_DIX)
- log_dbg("Pending flow with fd %d.", fd);
-#elif defined(BUILD_ETH_LLC)
- log_dbg("Pending flow with fd %d on SAP %d.", fd, ssap);
+#if defined(BUILD_ETH_LLC)
+ log_dbg("Assigned SAP %d for fd %d.", ssap, fd);
#endif
return 0;
}
@@ -1684,8 +1682,10 @@ static int eth_ipcp_flow_alloc_resp(int fd,
#endif
uint8_t r_addr[MAC_SIZE];
- if (ipcp_wait_flow_resp(fd) < 0)
+ if (ipcp_wait_flow_resp(fd) < 0) {
+ log_err("Failed to wait for flow response.");
return -1;
+ }
pthread_rwlock_wrlock(&eth_data.flows_lock);
#if defined(BUILD_ETH_DIX)
@@ -1694,6 +1694,7 @@ static int eth_ipcp_flow_alloc_resp(int fd,
ssap = bmp_allocate(eth_data.saps);
if (!bmp_is_id_valid(eth_data.saps, ssap)) {
pthread_rwlock_unlock(&eth_data.flows_lock);
+ log_err("Failed to allocate SSAP.");
return -1;
}
@@ -1719,14 +1720,13 @@ static int eth_ipcp_flow_alloc_resp(int fd,
bmp_release(eth_data.saps, eth_data.fd_to_ef[fd].sap);
pthread_rwlock_unlock(&eth_data.flows_lock);
#endif
+ log_err("Failed to respond to peer.");
return -1;
}
fset_add(eth_data.np1_flows, fd);
-#if defined(BUILD_ETH_DIX)
- log_dbg("Accepted flow, fd %d.", fd);
-#elif defined(BUILD_ETH_LLC)
- log_dbg("Accepted flow, fd %d, SAP %d.", fd, (uint8_t)ssap);
+#if defined(BUILD_ETH_LLC)
+ log_dbg("Assigned SAP %d for fd %d.", ssap, fd);
#endif
return 0;
}
@@ -1757,8 +1757,6 @@ static int eth_ipcp_flow_dealloc(int fd)
flow_dealloc(fd);
- log_dbg("Flow with fd %d deallocated.", fd);
-
return 0;
}
@@ -1790,8 +1788,10 @@ int main(int argc,
goto fail_data_init;
}
- if (ipcp_init(argc, argv, &eth_ops, THIS_TYPE) < 0)
+ if (ipcp_init(argc, argv, &eth_ops, THIS_TYPE) < 0) {
+ log_err("Failed to initialize IPCP.");
goto fail_init;
+ }
if (ipcp_start() < 0) {
log_err("Failed to start IPCP.");
diff --git a/src/ipcpd/ipcp.c b/src/ipcpd/ipcp.c
index eb83f3cc..5c1ffd03 100644
--- a/src/ipcpd/ipcp.c
+++ b/src/ipcpd/ipcp.c
@@ -339,23 +339,23 @@ static void free_msg(void * o)
}
-static void handle_bootstrap(ipcp_config_msg_t * conf_msg,
- ipcp_msg_t * ret_msg)
+static void do_bootstrap(ipcp_config_msg_t * conf_msg,
+ ipcp_msg_t * ret_msg)
{
struct ipcp_config conf;
- assert(ipcp_get_state() == IPCP_INIT);
+ log_info("Bootstrapping...");
if (ipcpi.ops->ipcp_bootstrap == NULL) {
log_err("Bootstrap unsupported.");
ret_msg->result = -ENOTSUP;
- return;
+ goto finish;
}
if (ipcp_get_state() != IPCP_INIT) {
log_err("IPCP in wrong state.");
ret_msg->result = -EIPCPSTATE;
- return;
+ goto finish;
}
conf = ipcp_config_msg_to_s(conf_msg);
@@ -364,25 +364,27 @@ static void handle_bootstrap(ipcp_config_msg_t * conf_msg,
ret_msg->layer_info = layer_info_s_to_msg(&conf.layer_info);
ipcp_set_state(IPCP_OPERATIONAL);
}
+ finish:
+ log_info("Finished bootstrapping: %d.", ret_msg->result);
}
-static void handle_enroll(const char * dst,
- ipcp_msg_t * ret_msg)
+static void do_enroll(const char * dst,
+ ipcp_msg_t * ret_msg)
{
struct layer_info info;
- assert(ipcp_get_state() == IPCP_INIT);
+ log_info("Enrolling with %s...", dst);
if (ipcpi.ops->ipcp_enroll == NULL) {
log_err("Enroll unsupported.");
ret_msg->result = -ENOTSUP;
- return;
+ goto finish;
}
if (ipcp_get_state() != IPCP_INIT) {
log_err("IPCP in wrong state.");
ret_msg->result = -EIPCPSTATE;
- return;
+ goto finish;
}
ret_msg->result = ipcpi.ops->ipcp_enroll(dst, &info);
@@ -390,63 +392,87 @@ static void handle_enroll(const char * dst,
ret_msg->layer_info = layer_info_s_to_msg(&info);
ipcp_set_state(IPCP_OPERATIONAL);
}
+ finish:
+ log_info("Finished enrolling with %s: %d.", dst, ret_msg->result);
}
-static void handle_connect(const char * dst,
- const char * comp,
- qosspec_t qs,
- ipcp_msg_t * ret_msg)
+static void do_connect(const char * dst,
+ const char * comp,
+ qosspec_t qs,
+ ipcp_msg_t * ret_msg)
{
+ log_info("Connecting %s to %s...", comp, dst);
+
if (ipcpi.ops->ipcp_connect == NULL) {
log_err("Connect unsupported.");
ret_msg->result = -ENOTSUP;
- return;
+ goto finish;
}
ret_msg->result = ipcpi.ops->ipcp_connect(dst, comp, qs);
+ finish:
+ log_info("Finished connecting: %d.", ret_msg->result);
}
-static void handle_disconnect(const char * dst,
- const char * comp,
- ipcp_msg_t * ret_msg)
+static void do_disconnect(const char * dst,
+ const char * comp,
+ ipcp_msg_t * ret_msg)
{
+ log_info("Disconnecting %s from %s...", comp, dst);
+
if (ipcpi.ops->ipcp_disconnect == NULL) {
log_err("Disconnect unsupported.");
ret_msg->result = -ENOTSUP;
- return;
+ goto finish;
}
ret_msg->result = ipcpi.ops->ipcp_disconnect(dst, comp);
+
+ finish:
+ log_info("Finished disconnecting %s from %s: %d.",
+ comp, dst, ret_msg->result);
}
-static void handle_reg(const uint8_t * hash,
- ipcp_msg_t * ret_msg)
+static void do_reg(const uint8_t * hash,
+ ipcp_msg_t * ret_msg)
{
+ log_info("Registering " HASH_FMT32 "...", HASH_VAL32(hash));
+
if (ipcpi.ops->ipcp_reg == NULL) {
log_err("Registration unsupported.");
ret_msg->result = -ENOTSUP;
- return;
+ goto finish;
}
ret_msg->result = ipcpi.ops->ipcp_reg(hash);
+ finish:
+ log_info("Finished registering " HASH_FMT32 " : %d.",
+ HASH_VAL32(hash), ret_msg->result);
}
-static void handle_unreg(const uint8_t * hash,
- ipcp_msg_t * ret_msg)
+static void do_unreg(const uint8_t * hash,
+ ipcp_msg_t * ret_msg)
{
+ log_info("Unregistering " HASH_FMT32 "...", HASH_VAL32(hash));
+
if (ipcpi.ops->ipcp_unreg == NULL) {
log_err("Unregistration unsupported.");
ret_msg->result = -ENOTSUP;
- return;
+ goto finish;
}
ret_msg->result = ipcpi.ops->ipcp_unreg(hash);
+ finish:
+ log_info("Finished unregistering " HASH_FMT32 ": %d.",
+ HASH_VAL32(hash), ret_msg->result);
}
-static void handle_query(const uint8_t * hash,
- ipcp_msg_t * ret_msg)
+static void do_query(const uint8_t * hash,
+ ipcp_msg_t * ret_msg)
{
+ /* TODO: Log this operation when IRMd has internal caches. */
+
if (ipcpi.ops->ipcp_query == NULL) {
log_err("Directory query unsupported.");
ret_msg->result = -ENOTSUP;
@@ -462,87 +488,99 @@ static void handle_query(const uint8_t * hash,
ret_msg->result = ipcpi.ops->ipcp_query(hash);
}
-static void handle_flow_alloc(pid_t pid,
- int flow_id,
- uint8_t * dst,
- qosspec_t qs,
- void * data,
- size_t len,
- ipcp_msg_t * ret_msg)
+static void do_flow_alloc(pid_t pid,
+ int flow_id,
+ uint8_t * dst,
+ qosspec_t qs,
+ void * data,
+ size_t len,
+ ipcp_msg_t * ret_msg)
{
int fd;
+ log_info("Allocating flow %d to " HASH_FMT32 ".",
+ flow_id, HASH_VAL32(dst));
+
if (ipcpi.ops->ipcp_flow_alloc == NULL) {
log_err("Flow allocation unsupported.");
ret_msg->result = -ENOTSUP;
- return;
+ goto finish;
}
if (ipcp_get_state() != IPCP_OPERATIONAL) {
log_err("IPCP in wrong state.");
ret_msg->result = -EIPCPSTATE;
- return;
+ goto finish;
}
fd = np1_flow_alloc(pid, flow_id);
if (fd < 0) {
- log_err("Failed allocating fd on flow_id %d.", flow_id);
+ log_err("Failed allocating n + 1 fd on flow_id %d.", flow_id);
ret_msg->result = -EFLOWDOWN;
- return;
+ goto finish;
}
ret_msg->result = ipcpi.ops->ipcp_flow_alloc(fd, dst, qs, data, len);
+ finish:
+ log_info("Finished allocating flow %d to " HASH_FMT32 ": %d.",
+ flow_id, HASH_VAL32(dst), ret_msg->result);
}
-static void handle_flow_join(pid_t pid,
- int flow_id,
- const uint8_t * dst,
- qosspec_t qs,
- ipcp_msg_t * ret_msg)
+static void do_flow_join(pid_t pid,
+ int flow_id,
+ const uint8_t * dst,
+ qosspec_t qs,
+ ipcp_msg_t * ret_msg)
{
int fd;
+ log_info("Joining layer " HASH_FMT32 ".", HASH_VAL32(dst));
+
if (ipcpi.ops->ipcp_flow_join == NULL) {
log_err("Broadcast unsupported.");
ret_msg->result = -ENOTSUP;
- return;
+ goto finish;
}
if (ipcp_get_state() != IPCP_OPERATIONAL) {
log_err("IPCP in wrong state.");
ret_msg->result = -EIPCPSTATE;
- return;
+ goto finish;
}
fd = np1_flow_alloc(pid, flow_id);
if (fd < 0) {
- log_err("Failed allocating fd on flow_id %d.", flow_id);
+ log_err("Failed allocating n + 1 fd on flow_id %d.", flow_id);
ret_msg->result = -1;
- return;
+ goto finish;
}
ret_msg->result = ipcpi.ops->ipcp_flow_join(fd, dst, qs);
+ finish:
+ log_info("Finished joining layer " HASH_FMT32 ".", HASH_VAL32(dst));
}
-static void handle_flow_alloc_resp(int resp,
- int flow_id,
- const void * data,
- size_t len,
- ipcp_msg_t * ret_msg)
+static void do_flow_alloc_resp(int resp,
+ int flow_id,
+ const void * data,
+ size_t len,
+ ipcp_msg_t * ret_msg)
{
int fd = -1;
+ log_info("Responding %d to alloc on flow_id %d.", resp, flow_id);
+
if (ipcpi.ops->ipcp_flow_alloc_resp == NULL) {
log_err("Flow_alloc_resp unsupported.");
ret_msg->result = -ENOTSUP;
- return;
+ goto finish;
}
if (ipcp_get_state() != IPCP_OPERATIONAL) {
log_err("IPCP in wrong state.");
ret_msg->result = -EIPCPSTATE;
- return;
+ goto finish;
}
if (resp == 0) {
@@ -550,39 +588,47 @@ static void handle_flow_alloc_resp(int resp,
if (fd < 0) {
log_warn("Flow_id %d is not known.", flow_id);
ret_msg->result = -1;
- return;
+ goto finish;
}
}
ret_msg->result = ipcpi.ops->ipcp_flow_alloc_resp(fd, resp, data, len);
+ finish:
+ log_info("Finished responding to allocation request: %d",
+ ret_msg->result);
}
-static void handle_flow_dealloc(int flow_id,
- int timeo_sec,
- ipcp_msg_t * ret_msg)
+static void do_flow_dealloc(int flow_id,
+ int timeo_sec,
+ ipcp_msg_t * ret_msg)
{
int fd;
+ log_info("Deallocating flow %d.", flow_id);
+
if (ipcpi.ops->ipcp_flow_dealloc == NULL) {
log_err("Flow deallocation unsupported.");
ret_msg->result = -ENOTSUP;
- return;
+ goto finish;
}
if (ipcp_get_state() != IPCP_OPERATIONAL) {
log_err("IPCP in wrong state.");
ret_msg->result = -EIPCPSTATE;
- return;
+ goto finish;
}
fd = np1_flow_dealloc(flow_id, timeo_sec);
if (fd < 0) {
log_warn("Could not deallocate flow_id %d.", flow_id);
ret_msg->result = -1;
- return;
+ goto finish;
}
ret_msg->result = ipcpi.ops->ipcp_flow_dealloc(fd);
+ finish:
+ log_info("Finished deallocating flow %d: %d.",
+ flow_id, ret_msg->result);
}
@@ -632,60 +678,59 @@ static void * mainloop(void * o)
switch (msg->code) {
case IPCP_MSG_CODE__IPCP_BOOTSTRAP:
- handle_bootstrap(msg->conf, &ret_msg);
+ do_bootstrap(msg->conf, &ret_msg);
break;
case IPCP_MSG_CODE__IPCP_ENROLL:
- handle_enroll(msg->dst, &ret_msg);
+ do_enroll(msg->dst, &ret_msg);
break;
case IPCP_MSG_CODE__IPCP_CONNECT:
qs = qos_spec_msg_to_s(msg->qosspec);
- handle_connect(msg->dst, msg->comp, qs, &ret_msg);
+ do_connect(msg->dst, msg->comp, qs, &ret_msg);
break;
case IPCP_MSG_CODE__IPCP_DISCONNECT:
- handle_disconnect(msg->dst, msg->comp, &ret_msg);
+ do_disconnect(msg->dst, msg->comp, &ret_msg);
break;
case IPCP_MSG_CODE__IPCP_REG:
assert(msg->hash.len == ipcp_dir_hash_len());
- handle_reg(msg->hash.data, &ret_msg);
+ do_reg(msg->hash.data, &ret_msg);
break;
case IPCP_MSG_CODE__IPCP_UNREG:
assert(msg->hash.len == ipcp_dir_hash_len());
- handle_unreg(msg->hash.data, &ret_msg);
+ do_unreg(msg->hash.data, &ret_msg);
break;
case IPCP_MSG_CODE__IPCP_QUERY:
assert(msg->hash.len == ipcp_dir_hash_len());
- handle_query(msg->hash.data, &ret_msg);
+ do_query(msg->hash.data, &ret_msg);
break;
case IPCP_MSG_CODE__IPCP_FLOW_ALLOC:
assert(msg->hash.len == ipcp_dir_hash_len());
assert(msg->pk.len > 0 ? msg->pk.data != NULL
: msg->pk.data == NULL);
qs = qos_spec_msg_to_s(msg->qosspec);
- handle_flow_alloc(msg->pid, msg->flow_id,
- msg->hash.data, qs,
- msg->pk.data, msg->pk.len,
- &ret_msg);
+ do_flow_alloc(msg->pid, msg->flow_id,
+ msg->hash.data, qs,
+ msg->pk.data, msg->pk.len,
+ &ret_msg);
break;
case IPCP_MSG_CODE__IPCP_FLOW_JOIN:
assert(msg->hash.len == ipcp_dir_hash_len());
qs = qos_spec_msg_to_s(msg->qosspec);
- handle_flow_join(msg->pid, msg->flow_id,
- msg->hash.data, qs, &ret_msg);
+ do_flow_join(msg->pid, msg->flow_id,
+ msg->hash.data, qs, &ret_msg);
break;
case IPCP_MSG_CODE__IPCP_FLOW_ALLOC_RESP:
assert(msg->pk.len > 0 ? msg->pk.data != NULL
: msg->pk.data == NULL);
- handle_flow_alloc_resp(msg->response, msg->flow_id,
- msg->pk.data, msg->pk.len,
- &ret_msg);
+ do_flow_alloc_resp(msg->response, msg->flow_id,
+ msg->pk.data, msg->pk.len,
+ &ret_msg);
break;
case IPCP_MSG_CODE__IPCP_FLOW_DEALLOC:
- handle_flow_dealloc(msg->flow_id, msg->timeo_sec,
- &ret_msg);
+ do_flow_dealloc(msg->flow_id, msg->timeo_sec, &ret_msg);
break;
default:
- ret_msg.result = -1;
+ ret_msg.result = -1;
log_err("Unknown message code: %d.", msg->code);
break;
}
@@ -830,14 +875,17 @@ int ipcp_init(int argc,
goto fail_rib_init;
}
- if (rib_reg(IPCP_INFO, &r_ops))
+ if (rib_reg(IPCP_INFO, &r_ops)) {
+ log_err("Failed to register rib.");
goto fail_rib_reg;
+ }
ipcpi.tpm = tpm_create(IPCP_MIN_THREADS, IPCP_ADD_THREADS,
mainloop, NULL);
- if (ipcpi.tpm == NULL)
+ if (ipcpi.tpm == NULL) {
+ log_err("Failed to create threadpool manager.");
goto fail_tpm_create;
-
+ }
list_head_init(&ipcpi.cmds);
diff --git a/src/ipcpd/local/main.c b/src/ipcpd/local/main.c
index a2f8c6dc..ef1c679b 100644
--- a/src/ipcpd/local/main.c
+++ b/src/ipcpd/local/main.c
@@ -149,25 +149,22 @@ static int local_ipcp_bootstrap(const struct ipcp_config * conf)
if (pthread_create(&local_data.packet_loop, NULL,
local_ipcp_packet_loop, NULL)) {
+ log_err("Failed to create pthread: %s", strerror(errno));
ipcp_set_state(IPCP_INIT);
return -1;
}
- log_info("Bootstrapped local IPCP with pid %d.", getpid());
-
return 0;
}
static int local_ipcp_reg(const uint8_t * hash)
{
if (shim_data_reg_add_entry(local_data.shim_data, hash)) {
- log_dbg("Failed to add " HASH_FMT32 " to local registry.",
+ log_err("Failed to add " HASH_FMT32 " to local registry.",
HASH_VAL32(hash));
return -1;
}
- log_info("Registered " HASH_FMT32 ".", HASH_VAL32(hash));
-
return 0;
}
@@ -226,8 +223,8 @@ static int local_ipcp_flow_alloc_resp(int fd,
const void * data,
size_t len)
{
- int out_fd = -1;
- time_t mpl = IPCP_LOCAL_MPL;
+ int out_fd;
+ time_t mpl = IPCP_LOCAL_MPL;
if (ipcp_wait_flow_resp(fd) < 0)
return -1;
diff --git a/src/ipcpd/shim-data.c b/src/ipcpd/shim-data.c
index 840b8224..34f875b1 100644
--- a/src/ipcpd/shim-data.c
+++ b/src/ipcpd/shim-data.c
@@ -30,7 +30,7 @@
#define OUROBOROS_PREFIX "shim-data"
-#include <ouroboros/endian.h>
+#include <ouroboros/hash.h>
#include <ouroboros/logs.h>
#include <ouroboros/list.h>
#include <ouroboros/time_utils.h>
@@ -446,9 +446,9 @@ uint64_t shim_data_dir_get_addr(struct shim_data * data,
pthread_rwlock_rdlock(&data->dir_lock);
entry = find_dir_entry_any(data, hash);
-
if (entry == NULL) {
pthread_rwlock_unlock(&data->dir_lock);
+ log_warn("No address for " HASH_FMT32 ".", HASH_VAL32(hash));
return 0; /* undefined behaviour, 0 may be a valid address */
}
diff --git a/src/ipcpd/udp/main.c b/src/ipcpd/udp/main.c
index aacf976e..8decb9be 100644
--- a/src/ipcpd/udp/main.c
+++ b/src/ipcpd/udp/main.c
@@ -323,8 +323,8 @@ static int udp_ipcp_port_alloc_reply(const struct sockaddr_in * saddr,
if (memcmp(&udp_data.fd_to_uf[s_eid].r_saddr, saddr, sizeof(*saddr))) {
pthread_rwlock_unlock(&udp_data.flows_lock);
- log_warn("Flow allocation reply for %u from wrong source.",
- s_eid);
+ log_err("Flow allocation reply for %u from wrong source.",
+ s_eid);
return -1;
}
@@ -334,7 +334,7 @@ static int udp_ipcp_port_alloc_reply(const struct sockaddr_in * saddr,
pthread_rwlock_unlock(&udp_data.flows_lock);
if (ipcp_flow_alloc_reply(s_eid, response, mpl, data, len) < 0) {
- log_dbg("Failed to reply to flow allocation.");
+ log_err("Failed to reply to flow allocation.");
return -1;
}
@@ -596,17 +596,17 @@ static int udp_ipcp_bootstrap(const struct ipcp_config * conf)
strcpy(ipcpi.layer_name, conf->layer_info.layer_name);
if (inet4_ntop(&conf->udp.ip_addr, ipstr) == NULL) {
- log_err("Failed to convert IP address");
+ log_err("Failed to convert IP address.");
return -1;
}
if (conf->udp.dns_addr != 0) {
if (inet4_ntop(&conf->udp.dns_addr, dnsstr) == NULL) {
- log_err("Failed to convert DNS address");
+ log_err("Failed to convert DNS address.");
return -1;
}
#ifndef HAVE_DDNS
- log_warn("DNS disabled at compile time, address ignored");
+ log_warn("DNS disabled at compile time, address ignored.");
#endif
} else {
strcpy(dnsstr, "not set");
@@ -633,14 +633,14 @@ static int udp_ipcp_bootstrap(const struct ipcp_config * conf)
if (pthread_create(&udp_data.mgmt_handler, NULL,
udp_ipcp_mgmt_handler, NULL)) {
- ipcp_set_state(IPCP_INIT);
+ log_err("Failed to create management thread.");
goto fail_bind;
}
for (i = 0; i < IPCP_UDP_RD_THR; ++i) {
if (pthread_create(&udp_data.packet_reader[i], NULL,
udp_ipcp_packet_reader, NULL)) {
- ipcp_set_state(IPCP_INIT);
+ log_err("Failed to create reader thread.");
goto fail_packet_reader;
}
}
@@ -648,7 +648,7 @@ static int udp_ipcp_bootstrap(const struct ipcp_config * conf)
for (i = 0; i < IPCP_UDP_WR_THR; ++i) {
if (pthread_create(&udp_data.packet_writer[i], NULL,
udp_ipcp_packet_writer, NULL)) {
- ipcp_set_state(IPCP_INIT);
+ log_err("failed to create writer thread.");
goto fail_packet_writer;
}
}
@@ -822,8 +822,10 @@ static int udp_ipcp_reg(const uint8_t * hash)
char * hashstr;
hashstr = malloc(ipcp_dir_hash_strlen() + 1);
- if (hashstr == NULL)
+ if (hashstr == NULL) {
+ log_err("Failed to malloc hashstr.");
return -1;
+ }
assert(hash);
@@ -845,11 +847,13 @@ static int udp_ipcp_reg(const uint8_t * hash)
ip_addr = udp_data.s_saddr.sin_addr.s_addr;
if (inet4_ntop(&ip_addr, ipstr) == NULL) {
+ log_err("Failed to convert IP address to string.");
free(hashstr);
return -1;
}
if (inet4_ntop(&dns_addr, dnsstr) == NULL) {
+ log_err("Failed to convert DNS address to string.");
free(hashstr);
return -1;
}
@@ -858,14 +862,13 @@ static int udp_ipcp_reg(const uint8_t * hash)
dnsstr, hashstr, DNS_TTL, ipstr);
if (ddns_send(cmd)) {
+ log_err("Failed to send DDNS message.");
shim_data_reg_del_entry(udp_data.shim_data, hash);
free(hashstr);
return -1;
}
}
#endif
- log_dbg("Registered " HASH_FMT32 ".", HASH_VAL32(hash));
-
free(hashstr);
return 0;
@@ -884,8 +887,10 @@ static int udp_ipcp_unreg(const uint8_t * hash)
assert(hash);
hashstr = malloc(ipcp_dir_hash_strlen() + 1);
- if (hashstr == NULL)
+ if (hashstr == NULL) {
+ log_err("Failed to malloc hashstr.");
return -1;
+ }
ipcp_hash_str(hashstr, hash);
@@ -896,6 +901,7 @@ static int udp_ipcp_unreg(const uint8_t * hash)
if (dns_addr != 0) {
if (inet4_ntop(&dns_addr, dnsstr) == NULL) {
+ log_err("Failed to convert DNS address to string.");
free(hashstr);
return -1;
}
@@ -908,8 +914,6 @@ static int udp_ipcp_unreg(const uint8_t * hash)
shim_data_reg_del_entry(udp_data.shim_data, hash);
- log_dbg("Unregistered " HASH_FMT32 ".", HASH_VAL32(hash));
-
free(hashstr);
return 0;
@@ -926,8 +930,10 @@ static int udp_ipcp_query(const uint8_t * hash)
assert(hash);
hashstr = malloc(ipcp_dir_hash_strlen() + 1);
- if (hashstr == NULL)
+ if (hashstr == NULL) {
+ log_err("Failed to malloc hashstr.");
return -ENOMEM;
+ }
ipcp_hash_str(hashstr, hash);
@@ -942,7 +948,7 @@ static int udp_ipcp_query(const uint8_t * hash)
if (dns_addr != 0) {
ip_addr = ddns_resolve(hashstr, dns_addr);
if (ip_addr == 0) {
- log_dbg("Could not resolve %s.", hashstr);
+ log_err("Could not resolve %s.", hashstr);
free(hashstr);
return -1;
}
@@ -950,7 +956,7 @@ static int udp_ipcp_query(const uint8_t * hash)
#endif
h = gethostbyname(hashstr);
if (h == NULL) {
- log_dbg("Could not resolve %s.", hashstr);
+ log_err("Could not resolve %s.", hashstr);
free(hashstr);
return -1;
}
@@ -981,8 +987,6 @@ static int udp_ipcp_flow_alloc(int fd,
uint32_t ip_addr = 0;
char ipstr[INET_ADDRSTRLEN];
- log_dbg("Allocating flow to " HASH_FMT32 ".", HASH_VAL32(dst));
-
(void) qs;
assert(dst);
@@ -998,6 +1002,7 @@ static int udp_ipcp_flow_alloc(int fd,
log_err("Could not convert IP address.");
return -1;
}
+
log_dbg("Destination UDP ipcp resolved at %s.", ipstr);
memset((char *) &r_saddr, 0, sizeof(r_saddr));
@@ -1019,8 +1024,6 @@ static int udp_ipcp_flow_alloc(int fd,
fset_add(udp_data.np1_flows, fd);
- log_dbg("Flow to %s pending on fd %d.", ipstr, fd);
-
return 0;
}
@@ -1032,8 +1035,10 @@ static int udp_ipcp_flow_alloc_resp(int fd,
struct sockaddr_in saddr;
int d_eid;
- if (ipcp_wait_flow_resp(fd) < 0)
+ if (ipcp_wait_flow_resp(fd) < 0) {
+ log_err("Failed to wait for flow response.");
return -1;
+ }
pthread_rwlock_rdlock(&udp_data.flows_lock);
@@ -1050,9 +1055,6 @@ static int udp_ipcp_flow_alloc_resp(int fd,
fset_add(udp_data.np1_flows, fd);
- log_dbg("Accepted flow, fd %d on eid %d.",
- fd, d_eid);
-
return 0;
}
@@ -1071,8 +1073,6 @@ static int udp_ipcp_flow_dealloc(int fd)
flow_dealloc(fd);
- log_dbg("Flow with fd %d deallocated.", fd);
-
return 0;
}
@@ -1101,8 +1101,10 @@ int main(int argc,
goto fail_data_init;
}
- if (ipcp_init(argc, argv, &udp_ops, THIS_TYPE) < 0)
+ if (ipcp_init(argc, argv, &udp_ops, THIS_TYPE) < 0) {
+ log_err("Failed to initialize IPCP.");
goto fail_init;
+ }
if (ipcp_start() < 0) {
log_err("Failed to start IPCP.");
diff --git a/src/ipcpd/unicast/dt.c b/src/ipcpd/unicast/dt.c
index 60975aed..f62b0d5b 100644
--- a/src/ipcpd/unicast/dt.c
+++ b/src/ipcpd/unicast/dt.c
@@ -399,26 +399,28 @@ static void handle_event(void * self,
const void * o)
{
struct conn * c;
+ int fd;
(void) self;
c = (struct conn *) o;
+ fd = c->flow_info.fd;
+
switch (event) {
case NOTIFY_DT_CONN_ADD:
#ifdef IPCP_FLOW_STATS
- stat_used(c->flow_info.fd, c->conn_info.addr);
+ stat_used(fd, c->conn_info.addr);
#endif
- psched_add(dt.psched, c->flow_info.fd);
- log_dbg("Added fd %d to packet scheduler.", c->flow_info.fd);
+ psched_add(dt.psched, fd);
+ log_dbg("Added fd %d to packet scheduler.", fd);
break;
case NOTIFY_DT_CONN_DEL:
#ifdef IPCP_FLOW_STATS
- stat_used(c->flow_info.fd, INVALID_ADDR);
+ stat_used(fd, INVALID_ADDR);
#endif
- psched_del(dt.psched, c->flow_info.fd);
- log_dbg("Removed fd %d from "
- "packet scheduler.", c->flow_info.fd);
+ psched_del(dt.psched, fd);
+ log_dbg("Removed fd %d from packet scheduler.", fd);
break;
default:
break;
@@ -642,6 +644,7 @@ int dt_init(struct dt_config cfg)
for (i = 0; i < PROG_MAX_FLOWS; ++i)
if (pthread_mutex_init(&dt.stat[i].lock, NULL)) {
+ log_err("Failed to init mutex for flow %d.", i);
for (j = 0; j < i; ++j)
pthread_mutex_destroy(&dt.stat[j].lock);
goto fail_stat_lock;
@@ -650,8 +653,10 @@ int dt_init(struct dt_config cfg)
dt.n_flows = 0;
#endif
sprintf(dtstr, "%s.%" PRIu64, DT, ipcpi.dt_addr);
- if (rib_reg(dtstr, &r_ops))
+ if (rib_reg(dtstr, &r_ops)) {
+ log_err("Failed to register RIB.");
goto fail_rib_reg;
+ }
return 0;
@@ -744,7 +749,7 @@ int dt_reg_comp(void * comp,
eid = bmp_allocate(dt.res_fds);
if (!bmp_is_id_valid(dt.res_fds, eid)) {
- log_warn("Reserved EIDs depleted.");
+ log_err("Cannot allocate EID.");
pthread_rwlock_unlock(&dt.lock);
return -EBADF;
}
diff --git a/src/ipcpd/unicast/fa.c b/src/ipcpd/unicast/fa.c
index c1560de0..f5fcdf87 100644
--- a/src/ipcpd/unicast/fa.c
+++ b/src/ipcpd/unicast/fa.c
@@ -359,7 +359,7 @@ static void packet_handler(int fd,
if (dt_write_packet(r_addr, qc, r_eid, sdb)) {
ipcp_sdb_release(sdb);
- log_warn("Failed to forward packet.");
+ log_dbg("Failed to forward packet.");
#ifdef IPCP_FLOW_STATS
pthread_rwlock_wrlock(&fa.flows_lock);
++flow->p_snd_f;
@@ -456,7 +456,7 @@ static size_t fa_wait_for_fa_msg(struct fa_msg * msg)
len = shm_du_buff_len(cmd->sdb);
if (len > MSGBUFSZ || len < sizeof(*msg)) {
- log_warn("Invalid flow allocation message (len: %zd)\n", len);
+ log_warn("Invalid flow allocation message (len: %zd).", len);
free(cmd);
return 0; /* No valid message */
}
@@ -539,6 +539,8 @@ static int fa_handle_flow_reply(struct fa_msg * msg,
fd = eid_to_fd(ntoh64(msg->r_eid));
if (fd < 0) {
pthread_rwlock_unlock(&fa.flows_lock);
+ log_err("Flow reply for unknown EID %" PRIu64 ".",
+ ntoh64(msg->r_eid));
return -ENOTALLOC;
}
@@ -553,8 +555,10 @@ static int fa_handle_flow_reply(struct fa_msg * msg,
pthread_rwlock_unlock(&fa.flows_lock);
- if (ipcp_flow_alloc_reply(fd, msg->response, mpl, data, dlen))
+ if (ipcp_flow_alloc_reply(fd, msg->response, mpl, data, dlen) < 0) {
+ log_err("Failed to reply for flow allocation on fd %d.", fd);
return -EIRMD;
+ }
return 0;
}
@@ -573,6 +577,8 @@ static int fa_handle_flow_update(struct fa_msg * msg,
fd = eid_to_fd(ntoh64(msg->r_eid));
if (fd < 0) {
pthread_rwlock_unlock(&fa.flows_lock);
+ log_err("Flow update for unknown EID %" PRIu64 ".",
+ ntoh64(msg->r_eid));
return -EPERM;
}
@@ -665,7 +671,7 @@ int fa_init(void)
fail_mtx:
pthread_rwlock_destroy(&fa.flows_lock);
fail_rwlock:
- log_err("Failed to initialize flow allocator.");
+
return -1;
}
@@ -721,7 +727,6 @@ int fa_start(void)
fail_thread:
psched_destroy(fa.psched);
fail_psched:
- log_err("Failed to start flow allocator.");
return -1;
}
@@ -779,6 +784,7 @@ int fa_alloc(int fd,
memcpy(shm_du_buff_head(sdb) + len, data, dlen);
if (dt_write_packet(addr, qc, fa.eid, sdb)) {
+ log_err("Failed to send flow allocation request packet.");
ipcp_sdb_release(sdb);
return -1;
}
@@ -808,10 +814,14 @@ int fa_alloc_resp(int fd,
flow = &fa.flows[fd];
- if (ipcp_wait_flow_resp(fd) < 0)
+ if (ipcp_wait_flow_resp(fd) < 0) {
+ log_err("Failed to wait for flow response.");
goto fail_alloc_resp;
+ }
if (ipcp_sdb_reserve(&sdb, sizeof(*msg) + len)) {
+ log_err("Failed to reserve sdb (%zu bytes).",
+ sizeof(*msg) + len);
goto fail_reserve;
}
@@ -830,8 +840,10 @@ int fa_alloc_resp(int fd,
pthread_rwlock_unlock(&fa.flows_lock);
- if (dt_write_packet(flow->r_addr, qc, fa.eid, sdb))
+ if (dt_write_packet(flow->r_addr, qc, fa.eid, sdb)) {
+ log_err("Failed to send flow allocation response packet.");
goto fail_packet;
+ }
if (response < 0) {
pthread_rwlock_rdlock(&fa.flows_lock);
@@ -881,6 +893,7 @@ static int fa_update_remote(int fd,
uint64_t r_addr;
if (ipcp_sdb_reserve(&sdb, sizeof(*msg))) {
+ log_err("Failed to reserve sdb (%zu bytes).", sizeof(*msg));
return -1;
}
@@ -904,6 +917,7 @@ static int fa_update_remote(int fd,
if (dt_write_packet(r_addr, qc, fa.eid, sdb)) {
+ log_err("Failed to send flow update packet.");
ipcp_sdb_release(sdb);
return -1;
}
@@ -928,6 +942,7 @@ void fa_np1_rcv(uint64_t eid,
fd = eid_to_fd(eid);
if (fd < 0) {
pthread_rwlock_unlock(&fa.flows_lock);
+ log_dbg("Received packet for unknown EID %" PRIu64 ".", eid);
ipcp_sdb_release(sdb);
return;
}
@@ -943,6 +958,7 @@ void fa_np1_rcv(uint64_t eid,
pthread_rwlock_unlock(&fa.flows_lock);
if (ipcp_flow_write(fd, sdb) < 0) {
+ log_dbg("Failed to write to flow %d.", fd);
ipcp_sdb_release(sdb);
#ifdef IPCP_FLOW_STATS
pthread_rwlock_wrlock(&fa.flows_lock);
diff --git a/src/ipcpd/unicast/main.c b/src/ipcpd/unicast/main.c
index e1c3d5d0..83504168 100644
--- a/src/ipcpd/unicast/main.c
+++ b/src/ipcpd/unicast/main.c
@@ -76,7 +76,7 @@ static int initialize_components(const struct ipcp_config * conf)
goto fail_addr_auth;
}
- log_dbg("IPCP got address %" PRIu64 ".", ipcpi.dt_addr);
+ log_info("IPCP got address %" PRIu64 ".", ipcpi.dt_addr);
if (ca_init(conf->unicast.cong_avoid)) {
log_err("Failed to initialize congestion avoidance.");
@@ -262,8 +262,6 @@ static int unicast_ipcp_bootstrap(const struct ipcp_config * conf)
goto fail_bootstrap;
}
- log_dbg("Bootstrapped in layer %s.", conf->layer_info.layer_name);
-
return 0;
fail_bootstrap:
diff --git a/src/ipcpd/unicast/pff.c b/src/ipcpd/unicast/pff.c
index 14c84449..0af17421 100644
--- a/src/ipcpd/unicast/pff.c
+++ b/src/ipcpd/unicast/pff.c
@@ -59,8 +59,10 @@ struct pff * pff_create(enum pol_pff pol)
}
pff->pff_i = pff->ops->create();
- if (pff->pff_i == NULL)
+ if (pff->pff_i == NULL) {
+ log_err("Failed to create PFF instance.");
goto err;
+ }
return pff;
err: