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>

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: