From ba427e63489757756cd2b244315b1a911071bbc2 Mon Sep 17 00:00:00 2001 From: Donatas Abraitis Date: Wed, 6 Apr 2022 22:15:57 +0300 Subject: [PATCH] ospfd, ospf6d: Add more logging details Basically just router-id or interface/IP. Signed-off-by: Donatas Abraitis --- ospf6d/ospf6_flood.c | 6 ++- ospf6d/ospf6_gr_helper.c | 5 ++- ospf6d/ospf6_message.c | 49 +++++++++++++--------- ospf6d/ospf6_neighbor.c | 21 ++++++---- ospfd/ospf_packet.c | 89 ++++++++++++++++++++++------------------ 5 files changed, 100 insertions(+), 70 deletions(-) diff --git a/ospf6d/ospf6_flood.c b/ospf6d/ospf6_flood.c index db1520ff20..d519b0e119 100644 --- a/ospf6d/ospf6_flood.c +++ b/ospf6d/ospf6_flood.c @@ -921,7 +921,11 @@ void ospf6_receive_lsa(struct ospf6_neighbor *from, /* (1) LSA Checksum */ if (!ospf6_lsa_checksum_valid(new->header)) { if (is_debug) - zlog_debug("Wrong LSA Checksum, discard"); + zlog_debug( + "Wrong LSA Checksum %s (Router-ID: %pI4) [Type:%s Checksum:%#06hx), discard", + from->name, &from->router_id, + ospf6_lstype_name(new->header->type), + ntohs(new->header->checksum)); ospf6_lsa_delete(new); return; } diff --git a/ospf6d/ospf6_gr_helper.c b/ospf6d/ospf6_gr_helper.c index 65ce078fcb..bf570a0b2d 100644 --- a/ospf6d/ospf6_gr_helper.c +++ b/ospf6d/ospf6_gr_helper.c @@ -280,8 +280,9 @@ int ospf6_process_grace_lsa(struct ospf6 *ospf6, struct ospf6_lsa *lsa, if (IS_DEBUG_OSPF6_GR) zlog_debug( - "%s, Grace LSA received from %pI4, grace interval:%u, restart reason :%s", - __func__, &restarter->router_id, grace_interval, + "%s, Grace LSA received from %s(%pI4), grace interval:%u, restart reason:%s", + __func__, restarter->name, &restarter->router_id, + grace_interval, ospf6_restart_reason_desc[restart_reason]); /* Verify Helper enabled globally */ diff --git a/ospf6d/ospf6_message.c b/ospf6d/ospf6_message.c index b7f261fcf9..a499190a11 100644 --- a/ospf6d/ospf6_message.c +++ b/ospf6d/ospf6_message.c @@ -410,26 +410,29 @@ static void ospf6_hello_recv(struct in6_addr *src, struct in6_addr *dst, /* HelloInterval check */ if (ntohs(hello->hello_interval) != oi->hello_interval) { zlog_warn( - "VRF %s: I/F %s HelloInterval mismatch: (my %d, rcvd %d)", - oi->interface->vrf->name, oi->interface->name, - oi->hello_interval, ntohs(hello->hello_interval)); + "VRF %s: I/F %s HelloInterval mismatch from %pI6 (%pI4): (my %d, rcvd %d)", + oi->interface->vrf->name, oi->interface->name, src, + &oh->router_id, oi->hello_interval, + ntohs(hello->hello_interval)); return; } /* RouterDeadInterval check */ if (ntohs(hello->dead_interval) != oi->dead_interval) { zlog_warn( - "VRF %s: I/F %s DeadInterval mismatch: (my %d, rcvd %d)", - oi->interface->vrf->name, oi->interface->name, - oi->dead_interval, ntohs(hello->dead_interval)); + "VRF %s: I/F %s DeadInterval mismatch from %pI6 (%pI4): (my %d, rcvd %d)", + oi->interface->vrf->name, oi->interface->name, src, + &oh->router_id, oi->dead_interval, + ntohs(hello->dead_interval)); return; } /* E-bit check */ - if (OSPF6_OPT_ISSET(hello->options, OSPF6_OPT_E) - != OSPF6_OPT_ISSET(oi->area->options, OSPF6_OPT_E)) { - zlog_warn("VRF %s: IF %s E-bit mismatch", - oi->interface->vrf->name, oi->interface->name); + if (OSPF6_OPT_ISSET(hello->options, OSPF6_OPT_E) != + OSPF6_OPT_ISSET(oi->area->options, OSPF6_OPT_E)) { + zlog_warn("VRF %s: IF %s E-bit mismatch from %pI6 (%pI4)", + oi->interface->vrf->name, oi->interface->name, src, + &oh->router_id); return; } @@ -687,8 +690,9 @@ static void ospf6_dbdesc_recv_master(struct ospf6_header *oh, if (ntohl(dbdesc->seqnum) != on->dbdesc_seqnum) { zlog_warn( - "DbDesc recv: Sequence number mismatch Nbr %s (%#lx expected)", - on->name, (unsigned long)on->dbdesc_seqnum); + "DbDesc recv: Sequence number mismatch Nbr %s (received %#lx, %#lx expected)", + on->name, (unsigned long)ntohl(dbdesc->seqnum), + (unsigned long)on->dbdesc_seqnum); thread_add_event(master, seqnumber_mismatch, on, 0, NULL); return; @@ -906,8 +910,9 @@ static void ospf6_dbdesc_recv_slave(struct ospf6_header *oh, if (ntohl(dbdesc->seqnum) != on->dbdesc_seqnum + 1) { zlog_warn( - "DbDesc slave recv: Sequence number mismatch Nbr %s (%#lx expected)", - on->name, (unsigned long)on->dbdesc_seqnum + 1); + "DbDesc slave recv: Sequence number mismatch Nbr %s (received %#lx, %#lx expected)", + on->name, (unsigned long)ntohl(dbdesc->seqnum), + (unsigned long)on->dbdesc_seqnum + 1); thread_add_event(master, seqnumber_mismatch, on, 0, NULL); return; @@ -1537,20 +1542,25 @@ static int ospf6_rxpacket_examin(struct ospf6_interface *oi, struct ospf6_header *oh, const unsigned bytesonwire) { + struct ospf6_neighbor *on; if (MSG_OK != ospf6_packet_examin(oh, bytesonwire)) return MSG_NG; + on = ospf6_neighbor_lookup(oh->router_id, oi); + /* Area-ID check */ if (oh->area_id != oi->area->area_id) { if (oh->area_id == OSPF_AREA_BACKBONE) zlog_warn( - "VRF %s: I/F %s Message may be via Virtual Link: not supported", - oi->interface->vrf->name, oi->interface->name); + "VRF %s: I/F %s (%s, Router-ID: %pI4) Message may be via Virtual Link: not supported", + oi->interface->vrf->name, oi->interface->name, + on ? on->name : "null", &oh->router_id); else zlog_warn( - "VRF %s: I/F %s Area-ID mismatch (my %pI4, rcvd %pI4)", + "VRF %s: I/F %s (%s, Router-ID: %pI4) Area-ID mismatch (my %pI4, rcvd %pI4)", oi->interface->vrf->name, oi->interface->name, + on ? on->name : "null", &oh->router_id, &oi->area->area_id, &oh->area_id); return MSG_NG; } @@ -1558,9 +1568,10 @@ static int ospf6_rxpacket_examin(struct ospf6_interface *oi, /* Instance-ID check */ if (oh->instance_id != oi->instance_id) { zlog_warn( - "VRF %s: I/F %s Instance-ID mismatch (my %u, rcvd %u)", + "VRF %s: I/F %s (%s, Router-ID: %pI4) Instance-ID mismatch (my %u, rcvd %u)", oi->interface->vrf->name, oi->interface->name, - oi->instance_id, oh->instance_id); + on ? on->name : "null", &oh->router_id, oi->instance_id, + oh->instance_id); return MSG_NG; } diff --git a/ospf6d/ospf6_neighbor.c b/ospf6d/ospf6_neighbor.c index 85002962ca..5ab5a49a4b 100644 --- a/ospf6d/ospf6_neighbor.c +++ b/ospf6d/ospf6_neighbor.c @@ -196,10 +196,12 @@ static void ospf6_neighbor_state_change(uint8_t next_state, /* log */ if (IS_OSPF6_DEBUG_NEIGHBOR(STATE)) { - zlog_debug("Neighbor state change %s: [%s]->[%s] (%s)", - on->name, ospf6_neighbor_state_str[prev_state], - ospf6_neighbor_state_str[next_state], - ospf6_neighbor_event_string(event)); + zlog_debug( + "Neighbor state change %s (Router-ID: %pI4): [%s]->[%s] (%s)", + on->name, &on->router_id, + ospf6_neighbor_state_str[prev_state], + ospf6_neighbor_state_str[next_state], + ospf6_neighbor_event_string(event)); } /* Optionally notify about adjacency changes */ @@ -209,10 +211,13 @@ static void ospf6_neighbor_state_change(uint8_t next_state, OSPF6_LOG_ADJACENCY_DETAIL) || (next_state == OSPF6_NEIGHBOR_FULL) || (next_state < prev_state))) - zlog_notice("AdjChg: Nbr %s: %s -> %s (%s)", on->name, - ospf6_neighbor_state_str[prev_state], - ospf6_neighbor_state_str[next_state], - ospf6_neighbor_event_string(event)); + zlog_notice( + "AdjChg: Nbr %pI4(%s) on %s: %s -> %s (%s)", + &on->router_id, + vrf_id_to_name(on->ospf6_if->interface->vrf->vrf_id), + on->name, ospf6_neighbor_state_str[prev_state], + ospf6_neighbor_state_str[next_state], + ospf6_neighbor_event_string(event)); if (prev_state == OSPF6_NEIGHBOR_FULL || next_state == OSPF6_NEIGHBOR_FULL) { diff --git a/ospfd/ospf_packet.c b/ospfd/ospf_packet.c index 2937c4ec0c..c4bccb3bc4 100644 --- a/ospfd/ospf_packet.c +++ b/ospfd/ospf_packet.c @@ -308,8 +308,10 @@ static int ospf_check_md5_digest(struct ospf_interface *oi, ck = ospf_crypt_key_lookup(OSPF_IF_PARAM(oi, auth_crypt), ospfh->u.crypt.key_id); if (ck == NULL) { - flog_warn(EC_OSPF_MD5, "interface %s: ospf_check_md5 no key %d", - IF_NAME(oi), ospfh->u.crypt.key_id); + flog_warn( + EC_OSPF_MD5, + "interface %s: ospf_check_md5 no key %d, Router-ID: %pI4", + IF_NAME(oi), ospfh->u.crypt.key_id, &ospfh->router_id); return 0; } @@ -320,9 +322,9 @@ static int ospf_check_md5_digest(struct ospf_interface *oi, && ntohl(nbr->crypt_seqnum) > ntohl(ospfh->u.crypt.crypt_seqnum)) { flog_warn( EC_OSPF_MD5, - "interface %s: ospf_check_md5 bad sequence %d (expect %d)", + "interface %s: ospf_check_md5 bad sequence %d (expect %d), Router-ID: %pI4", IF_NAME(oi), ntohl(ospfh->u.crypt.crypt_seqnum), - ntohl(nbr->crypt_seqnum)); + ntohl(nbr->crypt_seqnum), &ospfh->router_id); return 0; } @@ -345,9 +347,10 @@ static int ospf_check_md5_digest(struct ospf_interface *oi, /* compare the two */ if (memcmp((caddr_t)ospfh + length, digest, OSPF_AUTH_MD5_SIZE)) { - flog_warn(EC_OSPF_MD5, - "interface %s: ospf_check_md5 checksum mismatch", - IF_NAME(oi)); + flog_warn( + EC_OSPF_MD5, + "interface %s: ospf_check_md5 checksum mismatch, Router-ID: %pI4", + IF_NAME(oi), &ospfh->router_id); return 0; } @@ -426,10 +429,11 @@ static int ospf_make_md5_digest(struct ospf_interface *oi, if (stream_get_endp(op->s) != op->length) /* XXX size_t */ - flog_warn(EC_OSPF_MD5, - "%s: length mismatch stream %lu ospf_packet %u", - __func__, (unsigned long)stream_get_endp(op->s), - op->length); + flog_warn( + EC_OSPF_MD5, + "%s: length mismatch stream %lu ospf_packet %u, Router-ID %pI4", + __func__, (unsigned long)stream_get_endp(op->s), + op->length, &ospfh->router_id); return OSPF_AUTH_MD5_SIZE; } @@ -896,11 +900,11 @@ static void ospf_hello(struct ip *iph, struct ospf_header *ospfh, /* Compare Router Dead Interval. */ if (OSPF_IF_PARAM(oi, v_wait) != ntohl(hello->dead_interval)) { - flog_warn(EC_OSPF_PACKET, - "Packet %pI4 [Hello:RECV]: RouterDeadInterval mismatch (expected %u, but received %u).", - &ospfh->router_id, - OSPF_IF_PARAM(oi, v_wait), - ntohl(hello->dead_interval)); + flog_warn( + EC_OSPF_PACKET, + "Packet %pI4 [Hello:RECV]: RouterDeadInterval mismatch on %s (expected %u, but received %u).", + &ospfh->router_id, IF_NAME(oi), + OSPF_IF_PARAM(oi, v_wait), ntohl(hello->dead_interval)); return; } @@ -910,8 +914,8 @@ static void ospf_hello(struct ip *iph, struct ospf_header *ospfh, != ntohs(hello->hello_interval)) { flog_warn( EC_OSPF_PACKET, - "Packet %pI4 [Hello:RECV]: HelloInterval mismatch (expected %u, but received %u).", - &ospfh->router_id, + "Packet %pI4 [Hello:RECV]: HelloInterval mismatch on %s (expected %u, but received %u).", + &ospfh->router_id, IF_NAME(oi), OSPF_IF_PARAM(oi, v_hello), ntohs(hello->hello_interval)); return; @@ -919,8 +923,8 @@ static void ospf_hello(struct ip *iph, struct ospf_header *ospfh, } if (IS_DEBUG_OSPF_EVENT) - zlog_debug("Packet %pI4 [Hello:RECV]: Options %s vrf %s", - &ospfh->router_id, + zlog_debug("Packet %pI4 [Hello:RECV]: Options on %s %s vrf %s", + &ospfh->router_id, IF_NAME(oi), ospf_options_dump(hello->options), ospf_vrf_id_to_name(oi->ospf->vrf_id)); @@ -934,8 +938,8 @@ static void ospf_hello(struct ip *iph, struct ospf_header *ospfh, * relationship. */ flog_warn(EC_OSPF_PACKET, - "Packet %pI4 [Hello:RECV]: T-bit on, drop it.", - &ospfh->router_id); + "Packet %pI4 [Hello:RECV]: T-bit ON on %s, drop it.", + &ospfh->router_id, IF_NAME(oi)); return; } #endif /* REJECT_IF_TBIT_ON */ @@ -947,8 +951,8 @@ static void ospf_hello(struct ip *iph, struct ospf_header *ospfh, * the bit should be set in DD packet only. */ flog_warn(EC_OSPF_PACKET, - "Packet %pI4 [Hello:RECV]: O-bit abuse?", - &ospfh->router_id); + "Packet %pI4 [Hello:RECV]: O-bit abuse? on %s", + &ospfh->router_id, IF_NAME(oi)); #ifdef STRICT_OBIT_USAGE_CHECK return; /* Reject this packet. */ #else /* STRICT_OBIT_USAGE_CHECK */ @@ -2475,10 +2479,11 @@ static int ospf_check_auth(struct ospf_interface *oi, struct ospf_header *ospfh) if (IS_DEBUG_OSPF_PACKET(ospfh->type - 1, RECV)) flog_warn( EC_OSPF_PACKET, - "interface %s: auth-type mismatch, local %s, rcvd Null", + "interface %s: auth-type mismatch, local %s, rcvd Null, Router-ID %pI4", IF_NAME(oi), lookup_msg(ospf_auth_type_str, - iface_auth_type, NULL)); + iface_auth_type, NULL), + &ospfh->router_id); return 0; } if (!ospf_check_sum(ospfh)) { @@ -2497,18 +2502,20 @@ static int ospf_check_auth(struct ospf_interface *oi, struct ospf_header *ospfh) if (IS_DEBUG_OSPF_PACKET(ospfh->type - 1, RECV)) flog_warn( EC_OSPF_PACKET, - "interface %s: auth-type mismatch, local %s, rcvd Simple", + "interface %s: auth-type mismatch, local %s, rcvd Simple, Router-ID %pI4", IF_NAME(oi), lookup_msg(ospf_auth_type_str, - iface_auth_type, NULL)); + iface_auth_type, NULL), + &ospfh->router_id); return 0; } if (memcmp(OSPF_IF_PARAM(oi, auth_simple), ospfh->u.auth_data, OSPF_AUTH_SIMPLE_SIZE)) { if (IS_DEBUG_OSPF_PACKET(ospfh->type - 1, RECV)) - flog_warn(EC_OSPF_PACKET, - "interface %s: Simple auth failed", - IF_NAME(oi)); + flog_warn( + EC_OSPF_PACKET, + "interface %s: Simple auth failed, Router-ID %pI4", + IF_NAME(oi), &ospfh->router_id); return 0; } if (!ospf_check_sum(ospfh)) { @@ -2527,18 +2534,19 @@ static int ospf_check_auth(struct ospf_interface *oi, struct ospf_header *ospfh) if (IS_DEBUG_OSPF_PACKET(ospfh->type - 1, RECV)) flog_warn( EC_OSPF_PACKET, - "interface %s: auth-type mismatch, local %s, rcvd Cryptographic", + "interface %s: auth-type mismatch, local %s, rcvd Cryptographic, Router-ID %pI4", IF_NAME(oi), lookup_msg(ospf_auth_type_str, - iface_auth_type, NULL)); + iface_auth_type, NULL), + &ospfh->router_id); return 0; } if (ospfh->checksum) { if (IS_DEBUG_OSPF_PACKET(ospfh->type - 1, RECV)) flog_warn( EC_OSPF_PACKET, - "interface %s: OSPF header checksum is not 0", - IF_NAME(oi)); + "interface %s: OSPF header checksum is not 0, Router-ID %pI4", + IF_NAME(oi), &ospfh->router_id); return 0; } /* only MD5 crypto method can pass ospf_packet_examin() */ @@ -2551,9 +2559,10 @@ static int ospf_check_auth(struct ospf_interface *oi, struct ospf_header *ospfh) bug? */ !ospf_check_md5_digest(oi, ospfh)) { if (IS_DEBUG_OSPF_PACKET(ospfh->type - 1, RECV)) - flog_warn(EC_OSPF_MD5, - "interface %s: MD5 auth failed", - IF_NAME(oi)); + flog_warn( + EC_OSPF_MD5, + "interface %s: MD5 auth failed, Router-ID %pI4", + IF_NAME(oi), &ospfh->router_id); return 0; } return 1; @@ -2561,8 +2570,8 @@ static int ospf_check_auth(struct ospf_interface *oi, struct ospf_header *ospfh) if (IS_DEBUG_OSPF_PACKET(ospfh->type - 1, RECV)) flog_warn( EC_OSPF_PACKET, - "interface %s: invalid packet auth-type (%02x)", - IF_NAME(oi), pkt_auth_type); + "interface %s: invalid packet auth-type (%02x), Router-ID %pI4", + IF_NAME(oi), pkt_auth_type, &ospfh->router_id); return 0; } } -- 2.39.5