From: Donatas Abraitis Date: Wed, 6 Apr 2022 19:15:57 +0000 (+0300) Subject: ospfd, ospf6d: Add more logging details X-Git-Tag: frr-8.4.4~50^2~1 X-Git-Url: https://git.puffer.fish/?a=commitdiff_plain;h=0e327d9630cabdca69985969c8fdb0d54000f3fb;p=matthieu%2Ffrr.git ospfd, ospf6d: Add more logging details Basically just router-id or interface/IP. Signed-off-by: Donatas Abraitis (cherry picked from commit ba427e63489757756cd2b244315b1a911071bbc2) --- diff --git a/ospf6d/ospf6_flood.c b/ospf6d/ospf6_flood.c index bc9e2c3405..d174f9a572 100644 --- a/ospf6d/ospf6_flood.c +++ b/ospf6d/ospf6_flood.c @@ -936,7 +936,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 f8b37d803f..8cd7c51dbf 100644 --- a/ospf6d/ospf6_gr_helper.c +++ b/ospf6d/ospf6_gr_helper.c @@ -297,8 +297,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 360a9db0d6..bae5ab5682 100644 --- a/ospf6d/ospf6_message.c +++ b/ospf6d/ospf6_message.c @@ -424,26 +424,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; } @@ -701,8 +704,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; @@ -920,8 +924,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; @@ -1551,20 +1556,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; } @@ -1572,9 +1582,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 439b94c9af..4dbfce836e 100644 --- a/ospf6d/ospf6_neighbor.c +++ b/ospf6d/ospf6_neighbor.c @@ -201,10 +201,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 */ @@ -214,10 +216,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 b22fe5d99b..43a707f072 100644 --- a/ospfd/ospf_packet.c +++ b/ospfd/ospf_packet.c @@ -322,8 +322,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; } @@ -334,9 +336,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; } @@ -359,9 +361,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; } @@ -440,10 +443,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; } @@ -910,11 +914,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; } @@ -924,8 +928,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; @@ -933,8 +937,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)); @@ -948,8 +952,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 */ @@ -961,8 +965,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 */ @@ -2484,10 +2488,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)) { @@ -2506,18 +2511,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)) { @@ -2536,18 +2543,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() */ @@ -2560,9 +2568,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; @@ -2570,8 +2579,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; } }