vrrpd: improve logging

Signed-off-by: Quentin Young <qlyoung@cumulusnetworks.com>

vrrpd/vrrp.c

@@ -31,6 +31,20 @@
 #include "vrrp_arp.h"
 #include "vrrp_packet.h"
 
+#define VRRP_LOGPFX "[CORE] "
+
+const char *vrrp_state_names[3] = {
+	[VRRP_STATE_INITIALIZE] = "Initialize",
+	[VRRP_STATE_MASTER] = "Master",
+	[VRRP_STATE_BACKUP] = "Backup",
+};
+
+const char *vrrp_event_names[2] = {
+	[VRRP_EVENT_STARTUP] = "Startup",
+	[VRRP_EVENT_SHUTDOWN] = "Shutdown",
+};
+
+
 /* Utility functions ------------------------------------------------------- */
 
 /*
@@ -201,6 +215,12 @@ static void vrrp_send_advertisement(struct vrrp_vrouter *vr)
 
 	ssize_t sent = sendto(vr->sock, pkt, (size_t)pktlen, 0, &dest,
 			      sizeof(struct sockaddr_in));
+
+	if (sent < 0) {
+		zlog_warn(VRRP_LOGPFX VRRP_LOGPFX_VRID
+			  "Failed to send VRRP Advertisement",
+			  vr->vrid);
+	}
 }
 
 /* FIXME:
@@ -224,13 +244,16 @@ static int vrrp_socket(struct vrrp_vrouter *vr)
 	int ret;
 	struct connected *c;
 
-	errno = 0;
 	frr_elevate_privs(&vrrp_privs) {
 		vr->sock = socket(AF_INET, SOCK_RAW, IPPROTO_VRRP);
 	}
 
-	if (vr->sock < 0)
+	if (vr->sock < 0) {
-		perror("Error opening VRRP socket");
+		zlog_warn(VRRP_LOGPFX VRRP_LOGPFX_VRID
+			  "Can't create VRRP socket",
+			  vr->vrid);
+		return errno;
+	}
 
 	/* Join the multicast group.*/
 
@@ -248,9 +271,10 @@ static int vrrp_socket(struct vrrp_vrouter *vr)
 	ret = setsockopt(vr->sock, IPPROTO_IP, IP_ADD_MEMBERSHIP, (char *)&req,
 			 sizeof(struct ip_mreq));
 	if (ret < 0) {
-		// int err = errno;
+		zlog_warn(VRRP_LOGPFX VRRP_LOGPFX_VRID
-		/* VRRP_LOG(("cant do IP_ADD_MEMBERSHIP errno=%d\n", err)); */
+			  "Can't join VRRP multicast group",
-		return -1;
+			  vr->vrid);
+		return errno;
 	}
 	return 0;
 }
@@ -318,6 +342,8 @@ static void vrrp_change_state(struct vrrp_vrouter *vr, int to)
 	/* Call our handlers, then any subscribers */
 	vrrp_change_state_handlers[to](vr);
 	hook_call(vrrp_change_state_hook, vr, to);
+	zlog_info(VRRP_LOGPFX VRRP_LOGPFX_VRID "%s -> %s", vr->vrid,
+		  vrrp_state_names[vr->fsm.state], vrrp_state_names[to]);
 	vr->fsm.state = to;
 }
 
@@ -328,6 +354,8 @@ static int vrrp_adver_timer_expire(struct thread *thread)
 {
 	struct vrrp_vrouter *vr = thread->arg;
 
+	zlog_info(VRRP_LOGPFX VRRP_LOGPFX_VRID "Adver_Timer expired", vr->vrid);
+
 	if (vr->fsm.state == VRRP_STATE_BACKUP) {
 		vrrp_send_advertisement(vr);
 		/* FIXME: vrrp_send_gratuitous_arp(vr); */
@@ -340,11 +368,14 @@ static int vrrp_adver_timer_expire(struct thread *thread)
 }
 
 /*
- * Called when Master_Down timer expires.
+ * Called when Master_Down_Timer expires.
  */
 static int vrrp_master_down_timer_expire(struct thread *thread)
 {
-	/* struct vrrp_vrouter *vr = thread->arg; */
+	struct vrrp_vrouter *vr = thread->arg;
+
+	zlog_info(VRRP_LOGPFX VRRP_LOGPFX_VRID "Master_Down_Timer expired",
+		  vr->vrid);
 
 	return 0;
 }
@@ -378,10 +409,8 @@ static int vrrp_startup(struct vrrp_vrouter *vr)
 
 	/* Create socket */
 	int ret = vrrp_socket(vr);
-	if (ret < 0) {
+	if (ret < 0)
-		zlog_warn("Cannot create VRRP socket\n");
 		return ret;
-	}
 
 	/* Schedule listener */
 	/* ... */
@@ -442,6 +471,8 @@ static int (*vrrp_event_handlers[])(struct vrrp_vrouter *vr) = {
  */
 int vrrp_event(struct vrrp_vrouter *vr, int event)
 {
+	zlog_info(VRRP_LOGPFX VRRP_LOGPFX_VRID "'%s' event", vr->vrid,
+		  vrrp_event_names[vr->fsm.state]);
 	return vrrp_event_handlers[event](vr);
 }
 

vrrpd/vrrp.h

@@ -37,6 +37,8 @@
 #define VRRP_MCAST_GROUP_HEX 0xe0000012
 #define IPPROTO_VRRP 112
 
+#define VRRP_LOGPFX_VRID "[VRID: %u] "
+
 /* threadmaster */
 extern struct thread_master *master;
 
@@ -195,11 +197,14 @@ void vrrp_add_ip(struct vrrp_vrouter *vr, struct in_addr v4);
 
 /* State machine ----------------------------------------------------------- */
 
-#define VRRP_STATE_INITIALIZE 1
+#define VRRP_STATE_INITIALIZE 0
-#define VRRP_STATE_MASTER 2
+#define VRRP_STATE_MASTER 1
-#define VRRP_STATE_BACKUP 3
+#define VRRP_STATE_BACKUP 2
-#define VRRP_EVENT_STARTUP 1
+#define VRRP_EVENT_STARTUP 0
-#define VRRP_EVENT_SHUTDOWN 2
+#define VRRP_EVENT_SHUTDOWN 1
+
+extern const char *vrrp_state_names[3];
+extern const char *vrrp_event_names[2];
 
 /*
  * This hook called whenever the state of a Virtual Router changes, after the

vrrpd/vrrp_arp.c

@@ -36,6 +36,8 @@
 #include "vrrp.h"
 #include "vrrp_arp.h"
 
+#define VRRP_LOGPFX "[ARP] "
+
 /*
  * The size of the garp packet buffer should be the large enough to hold the
  * largest arp packet to be sent + the size of the link layer header for the
@@ -121,8 +123,9 @@ void vrrp_garp_send(struct vrrp_vrouter *vr, struct in_addr *v4)
 	/* If the interface doesn't support ARP, don't try sending */
 	if (ifp->flags & IFF_NOARP) {
 		zlog_warn(
+			VRRP_LOGPFX VRRP_LOGPFX_VRID
 			"Unable to send gratuitous ARP on %s; has IFF_NOARP\n",
-			ifp->name);
+			vr->vrid, ifp->name);
 		return;
 	}
 
@@ -131,12 +134,15 @@ void vrrp_garp_send(struct vrrp_vrouter *vr, struct in_addr *v4)
 
 	/* Send garp */
 	inet_ntop(AF_INET, v4, astr, sizeof(astr));
-	zlog_info("Sending gratuitous ARP on %s for %s", ifp->name, astr);
+	zlog_info(VRRP_LOGPFX VRRP_LOGPFX_VRID
+		  "Sending gratuitous ARP on %s for %s",
+		  vr->vrid, ifp->name, astr);
 	sent_len = vrrp_send_garp(ifp, garpbuf, garpbuf_len);
 
 	if (sent_len < 0)
-		zlog_warn("Error sending gratuitous ARP on %s for %s",
+		zlog_warn(VRRP_LOGPFX VRRP_LOGPFX_VRID
-			  ifp->name, astr);
+			  "Error sending gratuitous ARP on %s for %s",
+			  vr->vrid, ifp->name, astr);
 }
 
 void vrrp_garp_send_all(struct vrrp_vrouter *vr)
@@ -146,8 +152,9 @@ void vrrp_garp_send_all(struct vrrp_vrouter *vr)
 	/* If the interface doesn't support ARP, don't try sending */
 	if (ifp->flags & IFF_NOARP) {
 		zlog_warn(
+			VRRP_LOGPFX VRRP_LOGPFX_VRID
 			"Unable to send gratuitous ARP on %s; has IFF_NOARP\n",
-			ifp->name);
+			vr->vrid, ifp->name);
 		return;
 	}
 
@@ -170,10 +177,10 @@ void vrrp_garp_init(void)
 	}
 
 	if (garp_fd > 0)
-		zlog_info("Initialized gratuitous ARP socket");
+		zlog_info(VRRP_LOGPFX "Initialized gratuitous ARP socket");
 	else {
-		perror("Error initializing gratuitous ARP socket");
+		zlog_err(VRRP_LOGPFX
-		zlog_err("Error initializing gratuitous ARP socket");
+			 "Error initializing gratuitous ARP socket");
 		return;
 	}
 }

vrrpd/vrrp_vty.c

@@ -162,19 +162,7 @@ static void vrrp_show(struct vty *vty, struct vrrp_vrouter *vr)
 {
 	char ethstr[ETHER_ADDR_STRLEN];
 	char ipstr[INET_ADDRSTRLEN];
-	const char *stastr;
+	const char *stastr = vrrp_state_names[vr->fsm.state];
-
-	switch (vr->fsm.state) {
-	case VRRP_STATE_INITIALIZE:
-		stastr = "Initialize";
-		break;
-	case VRRP_STATE_MASTER:
-		stastr = "Master";
-		break;
-	case VRRP_STATE_BACKUP:
-		stastr = "Backup";
-		break;
-	}
 
 	struct ttable *tt = ttable_new(&ttable_styles[TTSTYLE_BLANK]);