Improve logging of sent and received messages.

* Standardize the logging format of sent and received messages:
  "msg-[in|out]: message type: lsr-id A.B.C.D [additional info]";

* Log sent label messages as well, not only the received ones;

* Move the logging of sent notification messages from
  send_notification_nbr() to send_notification_full(), this way notification
  triggered by the lde process are logged as well;

* Minor clean-up.

4 files changed, 54 insertions, 26 deletions

diff --git a/usr.sbin/ldpd/labelmapping.c b/usr.sbin/ldpd/labelmapping.c
index 5ed9800f2d8..4e70f8f3592 100644
--- a/usr.sbin/ldpd/labelmapping.c
+++ b/usr.sbin/ldpd/labelmapping.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: labelmapping.c,v 1.59 2016/08/08 16:45:51 renato Exp $ */
+/*	$OpenBSD: labelmapping.c,v 1.60 2016/09/02 17:08:02 renato Exp $ */
 
 /*
  * Copyright (c) 2014, 2015 Renato Westphal <renato@openbsd.org>
@@ -126,6 +126,10 @@ send_labelmessage(struct nbr *nbr, uint16_t type, struct mapping_head *mh)
 			return;
 		}
 
+		log_debug("msg-out: %s: lsr-id %s, fec %s, label %s",
+		    msg_name(type), inet_ntoa(nbr->id), log_map(&me->map),
+		    log_label(me->map.label));
+
 		TAILQ_REMOVE(mh, me, entry);
 		free(me);
 	}
@@ -394,31 +398,24 @@ recv_labelmessage(struct nbr *nbr, char *buf, uint16_t len, uint16_t type)
 		if (me->map.flags & F_MAP_REQ_ID)
 			me->map.requestid = reqid;
 
+		log_debug("msg-in: label mapping: lsr-id %s, fec %s, label %s",
+		    inet_ntoa(nbr->id), log_map(&me->map),
+		    log_label(me->map.label));
+
 		switch (type) {
 		case MSG_TYPE_LABELMAPPING:
-			log_debug("label mapping from lsr-id %s, FEC %s, "
-			    "label %s", inet_ntoa(nbr->id),
-			    log_map(&me->map), log_label(me->map.label));
 			imsg_type = IMSG_LABEL_MAPPING;
 			break;
 		case MSG_TYPE_LABELREQUEST:
-			log_debug("label request from lsr-id %s, FEC %s",
-			    inet_ntoa(nbr->id), log_map(&me->map));
 			imsg_type = IMSG_LABEL_REQUEST;
 			break;
 		case MSG_TYPE_LABELWITHDRAW:
-			log_debug("label withdraw from lsr-id %s, FEC %s",
-			    inet_ntoa(nbr->id), log_map(&me->map));
 			imsg_type = IMSG_LABEL_WITHDRAW;
 			break;
 		case MSG_TYPE_LABELRELEASE:
-			log_debug("label release from lsr-id %s, FEC %s",
-			    inet_ntoa(nbr->id), log_map(&me->map));
 			imsg_type = IMSG_LABEL_RELEASE;
 			break;
 		case MSG_TYPE_LABELABORTREQ:
-			log_debug("label abort from lsr-id %s, FEC %s",
-			    inet_ntoa(nbr->id), log_map(&me->map));
 			imsg_type = IMSG_LABEL_ABORT;
 			break;
 		default:
diff --git a/usr.sbin/ldpd/log.c b/usr.sbin/ldpd/log.c
index 782b27476c4..bfce33f804a 100644
--- a/usr.sbin/ldpd/log.c
+++ b/usr.sbin/ldpd/log.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: log.c,v 1.31 2016/08/08 21:42:13 renato Exp $ */
+/*	$OpenBSD: log.c,v 1.32 2016/09/02 17:08:02 renato Exp $ */
 
 /*
  * Copyright (c) 2003, 2004 Henning Brauer <henning@openbsd.org>
@@ -433,6 +433,39 @@ if_type_name(enum iface_type type)
 }
 
 const char *
+msg_name(uint16_t msg)
+{
+	static char buf[16];
+
+	switch (msg) {
+	case MSG_TYPE_NOTIFICATION:
+		return ("notification");
+	case MSG_TYPE_HELLO:
+		return ("hello");
+	case MSG_TYPE_INIT:
+		return ("initialization");
+	case MSG_TYPE_KEEPALIVE:
+		return ("keepalive");
+	case MSG_TYPE_ADDR:
+		return ("address");
+	case MSG_TYPE_ADDRWITHDRAW:
+		return ("address withdraw");
+	case MSG_TYPE_LABELMAPPING:
+		return ("label mapping");
+	case MSG_TYPE_LABELREQUEST:
+		return ("label request");
+	case MSG_TYPE_LABELWITHDRAW:
+		return ("label withdraw");
+	case MSG_TYPE_LABELRELEASE:
+		return ("label release");
+	case MSG_TYPE_LABELABORTREQ:
+	default:
+		snprintf(buf, sizeof(buf), "[%08x]", msg);
+		return (buf);
+	}
+}
+
+const char *
 status_code_name(uint32_t status)
 {
 	static char buf[16];
diff --git a/usr.sbin/ldpd/log.h b/usr.sbin/ldpd/log.h
index f7948a3b254..ca221e21848 100644
--- a/usr.sbin/ldpd/log.h
+++ b/usr.sbin/ldpd/log.h
@@ -1,4 +1,4 @@
-/*	$OpenBSD: log.h,v 1.14 2016/07/18 21:10:37 benno Exp $ */
+/*	$OpenBSD: log.h,v 1.15 2016/09/02 17:08:02 renato Exp $ */
 
 /*
  * Copyright (c) 2003, 2004 Henning Brauer <henning@openbsd.org>
@@ -55,6 +55,7 @@ const char	*socket_name(int);
 const char	*nbr_state_name(int);
 const char	*if_state_name(int);
 const char	*if_type_name(enum iface_type);
+const char	*msg_name(uint16_t);
 const char	*status_code_name(uint32_t);
 const char	*pw_type_name(uint16_t);
 void		 log_rtmsg(unsigned char);
diff --git a/usr.sbin/ldpd/notification.c b/usr.sbin/ldpd/notification.c
index 489001289a1..70fba63a4bc 100644
--- a/usr.sbin/ldpd/notification.c
+++ b/usr.sbin/ldpd/notification.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: notification.c,v 1.40 2016/07/16 19:20:16 renato Exp $ */
+/*	$OpenBSD: notification.c,v 1.41 2016/09/02 17:08:02 renato Exp $ */
 
 /*
  * Copyright (c) 2009 Michele Marchetto <michele@openbsd.org>
@@ -64,6 +64,11 @@ send_notification_full(struct tcp_conn *tcp, struct notify_msg *nm)
 		return;
 	}
 
+	if (tcp->nbr)
+		log_debug("msg-out: notification: lsr-id %s, status %s%s",
+		    inet_ntoa(tcp->nbr->id), status_code_name(nm->status_code),
+		    (nm->status_code & STATUS_FATAL) ? " (fatal)" : "");
+
 	evbuf_enqueue(&tcp->wbuf, buf);
 }
 
@@ -86,9 +91,6 @@ void
 send_notification_nbr(struct nbr *nbr, uint32_t status_code, uint32_t msg_id,
     uint16_t msg_type)
 {
-	log_debug("%s: lsr-id %s, status %s", __func__, inet_ntoa(nbr->id),
-	     status_code_name(status_code));
-
 	send_notification(status_code, nbr->tcp, msg_id, msg_type);
 	nbr_fsm(nbr, NBR_EVT_PDU_SENT);
 }
@@ -197,14 +199,9 @@ recv_notification(struct nbr *nbr, char *buf, uint16_t len)
 		}
 	}
 
-	if (st.status_code & htonl(STATUS_FATAL))
-		log_warnx("received notification from lsr-id %s: %s",
-		    inet_ntoa(nbr->id),
-		    status_code_name(ntohl(st.status_code)));
-	else
-		log_debug("received non-fatal notification from lsr-id "
-		    "%s: %s", inet_ntoa(nbr->id),
-		    status_code_name(ntohl(st.status_code)));
+	log_warnx("msg-in: notification: lsr-id %s, status %s%s",
+	    inet_ntoa(nbr->id), status_code_name(ntohl(st.status_code)),
+	    (st.status_code & htonl(STATUS_FATAL)) ? " (fatal)" : "");
 
 	if (st.status_code & htonl(STATUS_FATAL)) {
 		if (nbr->state == NBR_STA_OPENSENT)