Remi Locherer(remi.loche...@relo.ch) on 2021.11.03 22:23:44 +0100:
> On Tue, Nov 02, 2021 at 05:27:11PM +0000, Stuart Henderson wrote:
> > I've recently started seeing a number of flaps with ospfd/ospf6d
> > with invalid seq nums / "seq num mismatch, bad flags" logged.
> > Not quite sure what's going yet as they must be occurring on
> > various local switched segments on one nic and also on ethernet
> > wan circuits direct to router on a separate pcie nic, anyway
> > it's made it clear that very few of the log messages relating
> > to neighbours identify which interface is involved.
> >
> > I don't know if it makes sense to commit or not, but there's a
> > diff below adding the interface wherever the neighbour ID is logged
> > if anyone's interested (same changes to both ospfd and ospf6d).
> >
> >
> > Nov 2 11:29:30 ospfd[78532]: recv_db_description: neighbor ID
> > xxxxxxxxxx.2: invalid seq num, mine 20d22487 his 20d22485
> > Nov 2 11:29:30 ospf6d[89545]: recv_db_description: neighbor ID
> > xxxxxxxxxx.2: invalid seq num, mine 4cabc5c1 his 4cabc5c0
> > Nov 2 11:29:34 ospf6d[89545]: recv_db_description: neighbor ID
> > xxxxxxxxxx.1: invalid seq num, mine 98360a5 his 98360a4
> > Nov 2 11:29:34 ospfd[78532]: recv_db_description: neighbor ID
> > xxxxxxxxxx.1: invalid seq num, mine f708c646 his f708c645
> > Nov 2 11:29:38 ospfd[78532]: recv_db_description: neighbor ID
> > xxxxxxxxxx.11: invalid seq num, mine e4068bcc his e4068bcb
> > Nov 2 11:30:06 ospf6d[89545]: recv_db_description: neighbor ID
> > xxxxxxxxxx.3: seq num mismatch, bad flags
> > Nov 2 11:30:14 ospf6d[89545]: recv_db_description: neighbor ID
> > xxxxxxxxxx.1: invalid seq num, mine 98360ae his 98360ad
> > Nov 2 11:30:14 ospfd[78532]: recv_db_description: neighbor ID
> > xxxxxxxxxx.1: invalid seq num, mine f708c64f his f708c64e
> > Nov 2 11:30:22 ospfd[78532]: recv_db_description: neighbor ID
> > xxxxxxxxxx.2: invalid seq num, mine 20d22493 his 20d22490
> > Nov 2 11:30:22 ospfd[78532]: recv_db_description: neighbor ID
> > xxxxxxxxxx.2: invalid seq num, mine 20d22493 his 20d22492
> > Nov 2 11:30:39 ospfd[78532]: recv_db_description: neighbor ID
> > xxxxxxxxxx.2: invalid seq num, mine 20d2249c his 20d2249b
> > Nov 2 11:30:59 ospf6d[89545]: recv_db_description: neighbor ID
> > xxxxxxxxxx.11: seq num mismatch, bad flags
> > Nov 2 11:30:59 ospfd[78532]: recv_db_description: neighbor ID
> > xxxxxxxxxx.11: seq num mismatch, bad flags
> > Nov 2 11:31:09 ospfd[78532]: recv_db_description: neighbor ID
> > xxxxxxxxxx.1: invalid seq num, mine f708c65c his f708c65b
> >
>
> I think this addition makes sense. Over which link a neighbor is connected
> can only be looked up via ospfctl. It's valuable having this info in the
> logs when analysing past events.
I thought i had okayed this yesterday already ;)
Makes complete sense.
> Diff reads fine, applies and compiles.
same.
> OK remi
ok benno
>
> >
> > Index: ospf6d/database.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospf6d/database.c,v
> > retrieving revision 1.20
> > diff -u -p -r1.20 database.c
> > --- ospf6d/database.c 15 Jul 2020 14:47:41 -0000 1.20
> > +++ ospf6d/database.c 2 Nov 2021 17:11:38 -0000
> > @@ -60,9 +60,9 @@ send_db_description(struct nbr *nbr)
> > case NBR_STA_INIT:
> > case NBR_STA_2_WAY:
> > case NBR_STA_SNAP:
> > - log_debug("send_db_description: neighbor ID %s: "
> > + log_debug("send_db_description: neighbor ID %s (%s): "
> > "cannot send packet in state %s", inet_ntoa(nbr->id),
> > - nbr_state_name(nbr->state));
> > + nbr->iface->name, nbr_state_name(nbr->state));
> > goto fail;
> > case NBR_STA_XSTRT:
> > bits |= OSPF_DBD_MS | OSPF_DBD_M | OSPF_DBD_I;
> > @@ -160,8 +160,8 @@ recv_db_description(struct nbr *nbr, cha
> > int dupe = 0;
> >
> > if (len < sizeof(dd_hdr)) {
> > - log_warnx("recv_db_description: neighbor ID %s: "
> > - "bad packet size", inet_ntoa(nbr->id));
> > + log_warnx("recv_db_description: neighbor ID %s (%s): "
> > + "bad packet size", inet_ntoa(nbr->id), nbr->iface->name);
> > return;
> > }
> > memcpy(&dd_hdr, buf, sizeof(dd_hdr));
> > @@ -170,9 +170,10 @@ recv_db_description(struct nbr *nbr, cha
> >
> > /* db description packet sanity checks */
> > if (ntohs(dd_hdr.iface_mtu) > nbr->iface->mtu) {
> > - log_warnx("recv_db_description: neighbor ID %s: "
> > + log_warnx("recv_db_description: neighbor ID %s (%s): "
> > "invalid MTU %d expected %d", inet_ntoa(nbr->id),
> > - ntohs(dd_hdr.iface_mtu), nbr->iface->mtu);
> > + nbr->iface->name, ntohs(dd_hdr.iface_mtu),
> > + nbr->iface->mtu);
> > return;
> > }
> >
> > @@ -180,8 +181,9 @@ recv_db_description(struct nbr *nbr, cha
> > nbr->last_rx_bits == dd_hdr.bits &&
> > ntohl(dd_hdr.dd_seq_num) == nbr->dd_seq_num - nbr->dd_master ?
> > 1 : 0) {
> > - log_debug("recv_db_description: dupe from neighbor ID %s",
> > - inet_ntoa(nbr->id));
> > + log_debug("recv_db_description: dupe from "
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > dupe = 1;
> > }
> >
> > @@ -190,9 +192,9 @@ recv_db_description(struct nbr *nbr, cha
> > case NBR_STA_ATTEMPT:
> > case NBR_STA_2_WAY:
> > case NBR_STA_SNAP:
> > - log_debug("recv_db_description: neighbor ID %s: "
> > + log_debug("recv_db_description: neighbor ID %s (%s): "
> > "packet ignored in state %s", inet_ntoa(nbr->id),
> > - nbr_state_name(nbr->state));
> > + nbr->iface->name, nbr_state_name(nbr->state));
> > return;
> > case NBR_STA_INIT:
> > /* evaluate dr and bdr after issuing a 2-Way event */
> > @@ -222,10 +224,10 @@ recv_db_description(struct nbr *nbr, cha
> > /* M only case: we are master */
> > if (ntohl(dd_hdr.dd_seq_num) != nbr->dd_seq_num) {
> > log_warnx("recv_db_description: "
> > - "neighbor ID %s: "
> > + "neighbor ID %s (%s): "
> > "invalid seq num, mine %x his %x",
> > - inet_ntoa(nbr->id), nbr->dd_seq_num,
> > - ntohl(dd_hdr.dd_seq_num));
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr->dd_seq_num, ntohl(dd_hdr.dd_seq_num));
> > return;
> > }
> > nbr->dd_seq_num++;
> > @@ -241,9 +243,10 @@ recv_db_description(struct nbr *nbr, cha
> > }
> > } else {
> > /* ignore packet */
> > - log_debug("recv_db_description: neighbor ID %s: "
> > + log_debug("recv_db_description: neighbor ID %s (%s): "
> > "packet ignored in state %s (bad flags)",
> > - inet_ntoa(nbr->id), nbr_state_name(nbr->state));
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr_state_name(nbr->state));
> > }
> > break;
> > case NBR_STA_XCHNG:
> > @@ -251,16 +254,17 @@ recv_db_description(struct nbr *nbr, cha
> > case NBR_STA_FULL:
> > if (dd_hdr.bits & OSPF_DBD_I ||
> > !(dd_hdr.bits & OSPF_DBD_MS) == !nbr->dd_master) {
> > - log_warnx("recv_db_description: neighbor ID %s: "
> > - "seq num mismatch, bad flags", inet_ntoa(nbr->id));
> > + log_warnx("recv_db_description: neighbor ID %s (%s): "
> > + "seq num mismatch, bad flags", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > nbr_fsm(nbr, NBR_EVT_SEQ_NUM_MIS);
> > return;
> > }
> >
> > if (nbr->last_rx_options != dd_hdr.opts) {
> > - log_warnx("recv_db_description: neighbor ID %s: "
> > + log_warnx("recv_db_description: neighbor ID %s (%s): "
> > "seq num mismatch, bad options",
> > - inet_ntoa(nbr->id));
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > nbr_fsm(nbr, NBR_EVT_SEQ_NUM_MIS);
> > return;
> > }
> > @@ -273,10 +277,10 @@ recv_db_description(struct nbr *nbr, cha
> > }
> >
> > if (nbr->state != NBR_STA_XCHNG) {
> > - log_warnx("recv_db_description: neighbor ID %s: "
> > + log_warnx("recv_db_description: neighbor ID %s (%s): "
> > "invalid seq num, mine %x his %x",
> > - inet_ntoa(nbr->id), nbr->dd_seq_num,
> > - ntohl(dd_hdr.dd_seq_num));
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr->dd_seq_num, ntohl(dd_hdr.dd_seq_num));
> > nbr_fsm(nbr, NBR_EVT_SEQ_NUM_MIS);
> > return;
> > }
> > @@ -286,10 +290,10 @@ recv_db_description(struct nbr *nbr, cha
> > /* master */
> > if (ntohl(dd_hdr.dd_seq_num) != nbr->dd_seq_num) {
> > log_warnx("recv_db_description: "
> > - "neighbor ID %s: "
> > + "neighbor ID %s (%s): "
> > "invalid seq num, mine %x his %x, master",
> > - inet_ntoa(nbr->id), nbr->dd_seq_num,
> > - ntohl(dd_hdr.dd_seq_num));
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr->dd_seq_num, ntohl(dd_hdr.dd_seq_num));
> > nbr_fsm(nbr, NBR_EVT_SEQ_NUM_MIS);
> > return;
> > }
> > @@ -298,10 +302,10 @@ recv_db_description(struct nbr *nbr, cha
> > /* slave */
> > if (ntohl(dd_hdr.dd_seq_num) != nbr->dd_seq_num + 1) {
> > log_warnx("recv_db_description: "
> > - "neighbor ID %s: "
> > + "neighbor ID %s (%s): "
> > "invalid seq num, mine %x his %x, slave",
> > - inet_ntoa(nbr->id), nbr->dd_seq_num,
> > - ntohl(dd_hdr.dd_seq_num));
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr->dd_seq_num, ntohl(dd_hdr.dd_seq_num));
> > nbr_fsm(nbr, NBR_EVT_SEQ_NUM_MIS);
> > return;
> > }
> > @@ -385,8 +389,9 @@ db_tx_timer(int fd, short event, void *a
> > send_db_description(nbr);
> > break;
> > default:
> > - log_debug("db_tx_timer: neighbor ID %s: unknown neighbor state",
> > - inet_ntoa(nbr->id));
> > + log_debug("db_tx_timer: neighbor ID %s (%s): "
> > + "unknown neighbor state",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > break;
> > }
> >
> > Index: ospf6d/kroute.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospf6d/kroute.c,v
> > retrieving revision 1.65
> > diff -u -p -r1.65 kroute.c
> > --- ospf6d/kroute.c 10 Sep 2020 05:18:16 -0000 1.65
> > +++ ospf6d/kroute.c 2 Nov 2021 17:11:38 -0000
> > @@ -1107,7 +1107,7 @@ send_rtmsg(int fd, int action, struct kr
> > /*
> > * We don't have an interface address in that network,
> > * so we install a cloning route. The kernel will then
> > - * do neigbor discovery.
> > + * do neighbor discovery.
> > */
> > bzero(&ifp, sizeof(ifp));
> > ifp.addr.sdl_len = sizeof(struct sockaddr_dl);
> > Index: ospf6d/lsack.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospf6d/lsack.c,v
> > retrieving revision 1.8
> > diff -u -p -r1.8 lsack.c
> > --- ospf6d/lsack.c 28 Dec 2019 09:25:24 -0000 1.8
> > +++ ospf6d/lsack.c 2 Nov 2021 17:11:38 -0000
> > @@ -105,8 +105,8 @@ recv_ls_ack(struct nbr *nbr, char *buf,
> > case NBR_STA_XSTRT:
> > case NBR_STA_SNAP:
> > log_debug("recv_ls_ack: packet ignored in state %s, "
> > - "neighbor ID %s", nbr_state_name(nbr->state),
> > - inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", nbr_state_name(nbr->state),
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > break;
> > case NBR_STA_XCHNG:
> > case NBR_STA_LOAD:
> > @@ -127,7 +127,8 @@ recv_ls_ack(struct nbr *nbr, char *buf,
> > }
> > if (len > 0) {
> > log_warnx("recv_ls_ack: bad packet size, "
> > - "neighbor ID %s", inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return;
> > }
> > break;
> > @@ -141,8 +142,8 @@ lsa_hdr_check(struct nbr *nbr, struct ls
> > {
> > /* invalid age */
> > if ((ntohs(lsa_hdr->age) < 1) || (ntohs(lsa_hdr->age) > MAX_AGE)) {
> > - log_debug("lsa_hdr_check: invalid age, neighbor ID %s",
> > - inet_ntoa(nbr->id));
> > + log_debug("lsa_hdr_check: invalid age, neighbor ID %s (%s)",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > return (0);
> > }
> >
> > @@ -157,15 +158,17 @@ lsa_hdr_check(struct nbr *nbr, struct ls
> > case LSA_TYPE_EXTERNAL:
> > break;
> > default:
> > - log_debug("lsa_hdr_check: invalid LSA type %d, neighbor ID %s",
> > - lsa_hdr->type, inet_ntoa(nbr->id));
> > + log_debug("lsa_hdr_check: invalid LSA type %d, "
> > + "neighbor ID %s (%s)",
> > + lsa_hdr->type, inet_ntoa(nbr->id), nbr->iface->name);
> > return (0);
> > }
> >
> > /* invalid sequence number */
> > if (ntohl(lsa_hdr->seq_num) == RESV_SEQ_NUM) {
> > - log_debug("ls_hdr_check: invalid seq num, neighbor ID %s",
> > - inet_ntoa(nbr->id));
> > + log_debug("ls_hdr_check: invalid seq num, "
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return (0);
> > }
> >
> > Index: ospf6d/lsreq.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospf6d/lsreq.c,v
> > retrieving revision 1.12
> > diff -u -p -r1.12 lsreq.c
> > --- ospf6d/lsreq.c 19 Jan 2021 09:53:11 -0000 1.12
> > +++ ospf6d/lsreq.c 2 Nov 2021 17:11:38 -0000
> > @@ -96,8 +96,8 @@ recv_ls_req(struct nbr *nbr, char *buf,
> > case NBR_STA_XSTRT:
> > case NBR_STA_SNAP:
> > log_debug("recv_ls_req: packet ignored in state %s, "
> > - "neighbor ID %s", nbr_state_name(nbr->state),
> > - inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", nbr_state_name(nbr->state),
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > break;
> > case NBR_STA_XCHNG:
> > case NBR_STA_LOAD:
> > @@ -209,7 +209,8 @@ ls_req_tx_timer(int fd, short event, voi
> > return;
> > default:
> > log_debug("ls_req_tx_timer: unknown neighbor state, "
> > - "neighbor ID %s", inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > break;
> > }
> >
> > Index: ospf6d/lsupdate.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospf6d/lsupdate.c,v
> > retrieving revision 1.20
> > diff -u -p -r1.20 lsupdate.c
> > --- ospf6d/lsupdate.c 19 Jan 2021 09:53:11 -0000 1.20
> > +++ ospf6d/lsupdate.c 2 Nov 2021 17:11:38 -0000
> > @@ -243,8 +243,9 @@ recv_ls_update(struct nbr *nbr, char *bu
> > u_int32_t nlsa;
> >
> > if (len < sizeof(nlsa)) {
> > - log_warnx("recv_ls_update: bad packet size, neighbor ID %s",
> > - inet_ntoa(nbr->id));
> > + log_warnx("recv_ls_update: bad packet size, "
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return;
> > }
> > memcpy(&nlsa, buf, sizeof(nlsa));
> > @@ -260,8 +261,8 @@ recv_ls_update(struct nbr *nbr, char *bu
> > case NBR_STA_XSTRT:
> > case NBR_STA_SNAP:
> > log_debug("recv_ls_update: packet ignored in state %s, "
> > - "neighbor ID %s", nbr_state_name(nbr->state),
> > - inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", nbr_state_name(nbr->state),
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > break;
> > case NBR_STA_XCHNG:
> > case NBR_STA_LOAD:
> > @@ -269,13 +270,15 @@ recv_ls_update(struct nbr *nbr, char *bu
> > for (; nlsa > 0 && len > 0; nlsa--) {
> > if (len < sizeof(lsa)) {
> > log_warnx("recv_ls_update: bad packet size, "
> > - "neighbor ID %s", inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return;
> > }
> > memcpy(&lsa, buf, sizeof(lsa));
> > if (len < ntohs(lsa.len)) {
> > log_warnx("recv_ls_update: bad packet size, "
> > - "neighbor ID %s", inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return;
> > }
> > ospfe_imsg_compose_rde(IMSG_LS_UPD, nbr->peerid, 0,
> > @@ -285,7 +288,8 @@ recv_ls_update(struct nbr *nbr, char *bu
> > }
> > if (nlsa > 0 || len > 0) {
> > log_warnx("recv_ls_update: bad packet size, "
> > - "neighbor ID %s", inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return;
> > }
> > break;
> > @@ -497,8 +501,8 @@ ls_retrans_timer(int fd, short event, vo
> > if (nlsa == 0) {
> > /* something bad happened retry later */
> > log_warnx("ls_retrans_timer: sending LS update "
> > - "to neighbor ID %s failed",
> > - inet_ntoa(nbr->id));
> > + "to neighbor ID %s (%s) failed",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > log_debug("ls_retrans_timer: type: %04x len:
> > %u",
> > ntohs(le->le_ref->hdr.type),
> > le->le_ref->len);
> > Index: ospf6d/neighbor.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospf6d/neighbor.c,v
> > retrieving revision 1.17
> > diff -u -p -r1.17 neighbor.c
> > --- ospf6d/neighbor.c 22 Jun 2020 18:18:20 -0000 1.17
> > +++ ospf6d/neighbor.c 2 Nov 2021 17:11:38 -0000
> > @@ -136,9 +136,10 @@ nbr_fsm(struct nbr *nbr, enum nbr_event
> >
> > if (nbr_fsm_tbl[i].state == -1) {
> > /* event outside of the defined fsm, ignore it. */
> > - log_warnx("nbr_fsm: neighbor ID %s, "
> > + log_warnx("nbr_fsm: neighbor ID %s (%s), "
> > "event %s not expected in state %s",
> > - inet_ntoa(nbr->id), nbr_event_names[event],
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr_event_names[event],
> > nbr_state_name(old_state));
> > return (0);
> > }
> > @@ -184,8 +185,9 @@ nbr_fsm(struct nbr *nbr, enum nbr_event
> > }
> >
> > if (ret) {
> > - log_warnx("nbr_fsm: error changing state for neighbor ID %s, "
> > - "event %s, state %s", inet_ntoa(nbr->id),
> > + log_warnx("nbr_fsm: error changing state for neighbor "
> > + "ID %s (%s), event %s, state %s",
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > nbr_event_names[event], nbr_state_name(old_state));
> > return (-1);
> > }
> > @@ -218,10 +220,11 @@ nbr_fsm(struct nbr *nbr, enum nbr_event
> > if_fsm(nbr->iface, IF_EVT_NBR_CHNG);
> >
> > log_debug("nbr_fsm: event %s resulted in action %s and "
> > - "changing state for neighbor ID %s from %s to %s",
> > + "changing state for neighbor ID %s (%s) from %s to %s",
> > nbr_event_names[event],
> > nbr_action_names[nbr_fsm_tbl[i].action],
> > - inet_ntoa(nbr->id), nbr_state_name(old_state),
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr_state_name(old_state),
> > nbr_state_name(nbr->state));
> >
> > if (nbr->iface->type == IF_TYPE_VIRTUALLINK) {
> > @@ -437,8 +440,9 @@ nbr_adj_timer(int fd, short event, void
> > return;
> >
> > if (nbr->state & NBR_STA_ACTIVE && nbr->state != NBR_STA_FULL) {
> > - log_warnx("nbr_adj_timer: failed to form adjacency with %s",
> > - inet_ntoa(nbr->id));
> > + log_warnx("nbr_adj_timer: failed to form adjacency with "
> > + "neighbor ID %s on interface %s",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > nbr_fsm(nbr, NBR_EVT_ADJTMOUT);
> > }
> > }
> > @@ -527,7 +531,8 @@ nbr_act_snapshot(struct nbr *nbr)
> > /* we need to wait for the old snapshot to finish */
> > if (nbr->dd_snapshot) {
> > log_debug("nbr_act_snapshot: giving up, old snapshot running "
> > - "for neigbor ID %s", inet_ntoa(nbr->id));
> > + "for neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return (nbr_act_restart_dd(nbr));
> > }
> > ospfe_imsg_compose_rde(IMSG_DB_SNAPSHOT, nbr->peerid, 0, NULL, 0);
> > @@ -615,8 +620,9 @@ nbr_act_delete(struct nbr *nbr)
> > tv.tv_sec = DEFAULT_NBR_TMOUT;
> >
> > if (evtimer_add(&nbr->inactivity_timer, &tv)) {
> > - log_warnx("nbr_act_delete: error scheduling neighbor ID %s "
> > - "for removal", inet_ntoa(nbr->id));
> > + log_warnx("nbr_act_delete: error scheduling "
> > + "neighbor ID %s (%s) for removal",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > }
> >
> > return (nbr_act_clear_lists(nbr));
> > @@ -640,7 +646,8 @@ nbr_act_clear_lists(struct nbr *nbr)
> > int
> > nbr_act_hello_check(struct nbr *nbr)
> > {
> > - log_debug("nbr_act_hello_check: neighbor ID %s", inet_ntoa(nbr->id));
> > + log_debug("nbr_act_hello_check: neighbor ID %s (%s)",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> >
> > return (-1);
> > }
> > Index: ospfd/database.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospfd/database.c,v
> > retrieving revision 1.34
> > diff -u -p -r1.34 database.c
> > --- ospfd/database.c 15 Jul 2019 18:26:39 -0000 1.34
> > +++ ospfd/database.c 2 Nov 2021 17:11:38 -0000
> > @@ -62,9 +62,9 @@ send_db_description(struct nbr *nbr)
> > case NBR_STA_INIT:
> > case NBR_STA_2_WAY:
> > case NBR_STA_SNAP:
> > - log_debug("send_db_description: neighbor ID %s: "
> > + log_debug("send_db_description: neighbor ID %s (%s): "
> > "cannot send packet in state %s", inet_ntoa(nbr->id),
> > - nbr_state_name(nbr->state));
> > + nbr->iface->name, nbr_state_name(nbr->state));
> > goto fail;
> > case NBR_STA_XSTRT:
> > bits |= OSPF_DBD_MS | OSPF_DBD_M | OSPF_DBD_I;
> > @@ -166,8 +166,8 @@ recv_db_description(struct nbr *nbr, cha
> > int dupe = 0;
> >
> > if (len < sizeof(dd_hdr)) {
> > - log_warnx("recv_db_description: neighbor ID %s: "
> > - "bad packet size", inet_ntoa(nbr->id));
> > + log_warnx("recv_db_description: neighbor ID %s (%s): "
> > + "bad packet size", inet_ntoa(nbr->id), nbr->iface->name);
> > return;
> > }
> > memcpy(&dd_hdr, buf, sizeof(dd_hdr));
> > @@ -176,9 +176,10 @@ recv_db_description(struct nbr *nbr, cha
> >
> > /* db description packet sanity checks */
> > if (ntohs(dd_hdr.iface_mtu) > nbr->iface->mtu) {
> > - log_warnx("recv_db_description: neighbor ID %s: "
> > + log_warnx("recv_db_description: neighbor ID %s (%s): "
> > "invalid MTU %d expected %d", inet_ntoa(nbr->id),
> > - ntohs(dd_hdr.iface_mtu), nbr->iface->mtu);
> > + nbr->iface->name, ntohs(dd_hdr.iface_mtu),
> > + nbr->iface->mtu);
> > return;
> > }
> >
> > @@ -186,8 +187,9 @@ recv_db_description(struct nbr *nbr, cha
> > nbr->last_rx_bits == dd_hdr.bits &&
> > ntohl(dd_hdr.dd_seq_num) == nbr->dd_seq_num - nbr->dd_master ?
> > 1 : 0) {
> > - log_debug("recv_db_description: dupe from neighbor ID %s",
> > - inet_ntoa(nbr->id));
> > + log_debug("recv_db_description: dupe from "
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > dupe = 1;
> > }
> >
> > @@ -196,9 +198,9 @@ recv_db_description(struct nbr *nbr, cha
> > case NBR_STA_ATTEMPT:
> > case NBR_STA_2_WAY:
> > case NBR_STA_SNAP:
> > - log_debug("recv_db_description: neighbor ID %s: "
> > + log_debug("recv_db_description: neighbor ID %s (%s): "
> > "packet ignored in state %s", inet_ntoa(nbr->id),
> > - nbr_state_name(nbr->state));
> > + nbr->iface->name, nbr_state_name(nbr->state));
> > return;
> > case NBR_STA_INIT:
> > /* evaluate dr and bdr after issuing a 2-Way event */
> > @@ -212,10 +214,10 @@ recv_db_description(struct nbr *nbr, cha
> > return;
> > nbr->capa_options = dd_hdr.opts;
> > if ((nbr->capa_options & nbr->options) != nbr->options) {
> > - log_warnx("recv_db_description: neighbor ID %s "
> > + log_warnx("recv_db_description: neighbor ID %s (%s) "
> > "sent inconsistent options %x vs. %x",
> > - inet_ntoa(nbr->id), nbr->capa_options,
> > - nbr->options);
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr->capa_options, nbr->options);
> > }
> > /*
> > * check bits: either I,M,MS or only M
> > @@ -235,10 +237,10 @@ recv_db_description(struct nbr *nbr, cha
> > /* M only case: we are master */
> > if (ntohl(dd_hdr.dd_seq_num) != nbr->dd_seq_num) {
> > log_warnx("recv_db_description: "
> > - "neighbor ID %s: "
> > + "neighbor ID %s (%s): "
> > "invalid seq num, mine %x his %x",
> > - inet_ntoa(nbr->id), nbr->dd_seq_num,
> > - ntohl(dd_hdr.dd_seq_num));
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr->dd_seq_num, ntohl(dd_hdr.dd_seq_num));
> > return;
> > }
> > nbr->dd_seq_num++;
> > @@ -254,9 +256,10 @@ recv_db_description(struct nbr *nbr, cha
> > }
> > } else {
> > /* ignore packet */
> > - log_debug("recv_db_description: neighbor ID %s: "
> > + log_debug("recv_db_description: neighbor ID %s (%s): "
> > "packet ignored in state %s (bad flags)",
> > - inet_ntoa(nbr->id), nbr_state_name(nbr->state));
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr_state_name(nbr->state));
> > }
> > break;
> > case NBR_STA_XCHNG:
> > @@ -264,16 +267,17 @@ recv_db_description(struct nbr *nbr, cha
> > case NBR_STA_FULL:
> > if (dd_hdr.bits & OSPF_DBD_I ||
> > !(dd_hdr.bits & OSPF_DBD_MS) == !nbr->dd_master) {
> > - log_warnx("recv_db_description: neighbor ID %s: "
> > - "seq num mismatch, bad flags", inet_ntoa(nbr->id));
> > + log_warnx("recv_db_description: neighbor ID %s (%s): "
> > + "seq num mismatch, bad flags", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > nbr_fsm(nbr, NBR_EVT_SEQ_NUM_MIS);
> > return;
> > }
> >
> > if (nbr->last_rx_options != dd_hdr.opts) {
> > - log_warnx("recv_db_description: neighbor ID %s: "
> > + log_warnx("recv_db_description: neighbor ID %s (%s): "
> > "seq num mismatch, bad options",
> > - inet_ntoa(nbr->id));
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > nbr_fsm(nbr, NBR_EVT_SEQ_NUM_MIS);
> > return;
> > }
> > @@ -286,10 +290,10 @@ recv_db_description(struct nbr *nbr, cha
> > }
> >
> > if (nbr->state != NBR_STA_XCHNG) {
> > - log_warnx("recv_db_description: neighbor ID %s: "
> > + log_warnx("recv_db_description: neighbor ID %s (%s): "
> > "invalid seq num, mine %x his %x",
> > - inet_ntoa(nbr->id), nbr->dd_seq_num,
> > - ntohl(dd_hdr.dd_seq_num));
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr->dd_seq_num, ntohl(dd_hdr.dd_seq_num));
> > nbr_fsm(nbr, NBR_EVT_SEQ_NUM_MIS);
> > return;
> > }
> > @@ -299,10 +303,10 @@ recv_db_description(struct nbr *nbr, cha
> > /* master */
> > if (ntohl(dd_hdr.dd_seq_num) != nbr->dd_seq_num) {
> > log_warnx("recv_db_description: "
> > - "neighbor ID %s: "
> > + "neighbor ID %s (%s): "
> > "invalid seq num, mine %x his %x, master",
> > - inet_ntoa(nbr->id), nbr->dd_seq_num,
> > - ntohl(dd_hdr.dd_seq_num));
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr->dd_seq_num, ntohl(dd_hdr.dd_seq_num));
> > nbr_fsm(nbr, NBR_EVT_SEQ_NUM_MIS);
> > return;
> > }
> > @@ -311,10 +315,10 @@ recv_db_description(struct nbr *nbr, cha
> > /* slave */
> > if (ntohl(dd_hdr.dd_seq_num) != nbr->dd_seq_num + 1) {
> > log_warnx("recv_db_description: "
> > - "neighbor ID %s: "
> > + "neighbor ID %s (%s): "
> > "invalid seq num, mine %x his %x, slave",
> > - inet_ntoa(nbr->id), nbr->dd_seq_num,
> > - ntohl(dd_hdr.dd_seq_num));
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr->dd_seq_num, ntohl(dd_hdr.dd_seq_num));
> > nbr_fsm(nbr, NBR_EVT_SEQ_NUM_MIS);
> > return;
> > }
> > @@ -398,8 +402,9 @@ db_tx_timer(int fd, short event, void *a
> > send_db_description(nbr);
> > break;
> > default:
> > - log_debug("db_tx_timer: neighbor ID %s: unknown neighbor state",
> > - inet_ntoa(nbr->id));
> > + log_debug("db_tx_timer: neighbor ID %s (%s): "
> > + "unknown neighbor state",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > break;
> > }
> >
> > Index: ospfd/lsack.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospfd/lsack.c,v
> > retrieving revision 1.22
> > diff -u -p -r1.22 lsack.c
> > --- ospfd/lsack.c 15 Jul 2019 18:26:39 -0000 1.22
> > +++ ospfd/lsack.c 2 Nov 2021 17:11:38 -0000
> > @@ -111,8 +111,8 @@ recv_ls_ack(struct nbr *nbr, char *buf,
> > case NBR_STA_XSTRT:
> > case NBR_STA_SNAP:
> > log_debug("recv_ls_ack: packet ignored in state %s, "
> > - "neighbor ID %s", nbr_state_name(nbr->state),
> > - inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", nbr_state_name(nbr->state),
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > break;
> > case NBR_STA_XCHNG:
> > case NBR_STA_LOAD:
> > @@ -133,7 +133,8 @@ recv_ls_ack(struct nbr *nbr, char *buf,
> > }
> > if (len > 0) {
> > log_warnx("recv_ls_ack: bad packet size, "
> > - "neighbor ID %s", inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return;
> > }
> > break;
> > @@ -147,8 +148,8 @@ lsa_hdr_check(struct nbr *nbr, struct ls
> > {
> > /* invalid age */
> > if ((ntohs(lsa_hdr->age) < 1) || (ntohs(lsa_hdr->age) > MAX_AGE)) {
> > - log_debug("lsa_hdr_check: invalid age, neighbor ID %s",
> > - inet_ntoa(nbr->id));
> > + log_debug("lsa_hdr_check: invalid age, neighbor ID %s (%s)",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > return (0);
> > }
> >
> > @@ -161,15 +162,17 @@ lsa_hdr_check(struct nbr *nbr, struct ls
> > case LSA_TYPE_EXTERNAL:
> > break;
> > default:
> > - log_debug("lsa_hdr_check: invalid LSA type %d, neighbor ID %s",
> > - lsa_hdr->type, inet_ntoa(nbr->id));
> > + log_debug("lsa_hdr_check: invalid LSA type %d, "
> > + "neighbor ID %s (%s)",
> > + lsa_hdr->type, inet_ntoa(nbr->id), nbr->iface->name);
> > return (0);
> > }
> >
> > /* invalid sequence number */
> > if (ntohl(lsa_hdr->seq_num) == RESV_SEQ_NUM) {
> > - log_debug("ls_hdr_check: invalid seq num, neighbor ID %s",
> > - inet_ntoa(nbr->id));
> > + log_debug("ls_hdr_check: invalid seq num, "
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return (0);
> > }
> >
> > Index: ospfd/lsreq.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospfd/lsreq.c,v
> > retrieving revision 1.22
> > diff -u -p -r1.22 lsreq.c
> > --- ospfd/lsreq.c 19 Jan 2021 09:25:53 -0000 1.22
> > +++ ospfd/lsreq.c 2 Nov 2021 17:11:38 -0000
> > @@ -99,8 +99,8 @@ recv_ls_req(struct nbr *nbr, char *buf,
> > case NBR_STA_XSTRT:
> > case NBR_STA_SNAP:
> > log_debug("recv_ls_req: packet ignored in state %s, "
> > - "neighbor ID %s", nbr_state_name(nbr->state),
> > - inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", nbr_state_name(nbr->state),
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > break;
> > case NBR_STA_XCHNG:
> > case NBR_STA_LOAD:
> > @@ -212,7 +212,8 @@ ls_req_tx_timer(int fd, short event, voi
> > return;
> > default:
> > log_debug("ls_req_tx_timer: unknown neighbor state, "
> > - "neighbor ID %s", inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > break;
> > }
> >
> > Index: ospfd/lsupdate.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospfd/lsupdate.c,v
> > retrieving revision 1.49
> > diff -u -p -r1.49 lsupdate.c
> > --- ospfd/lsupdate.c 19 Jan 2021 09:25:53 -0000 1.49
> > +++ ospfd/lsupdate.c 2 Nov 2021 17:11:38 -0000
> > @@ -238,8 +238,9 @@ recv_ls_update(struct nbr *nbr, char *bu
> > u_int32_t nlsa;
> >
> > if (len < sizeof(nlsa)) {
> > - log_warnx("recv_ls_update: bad packet size, neighbor ID %s",
> > - inet_ntoa(nbr->id));
> > + log_warnx("recv_ls_update: bad packet size, "
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return;
> > }
> > memcpy(&nlsa, buf, sizeof(nlsa));
> > @@ -255,8 +256,8 @@ recv_ls_update(struct nbr *nbr, char *bu
> > case NBR_STA_XSTRT:
> > case NBR_STA_SNAP:
> > log_debug("recv_ls_update: packet ignored in state %s, "
> > - "neighbor ID %s", nbr_state_name(nbr->state),
> > - inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", nbr_state_name(nbr->state),
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > break;
> > case NBR_STA_XCHNG:
> > case NBR_STA_LOAD:
> > @@ -264,13 +265,15 @@ recv_ls_update(struct nbr *nbr, char *bu
> > for (; nlsa > 0 && len > 0; nlsa--) {
> > if (len < sizeof(lsa)) {
> > log_warnx("recv_ls_update: bad packet size, "
> > - "neighbor ID %s", inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return;
> > }
> > memcpy(&lsa, buf, sizeof(lsa));
> > if (len < ntohs(lsa.len)) {
> > log_warnx("recv_ls_update: bad packet size, "
> > - "neighbor ID %s", inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return;
> > }
> > ospfe_imsg_compose_rde(IMSG_LS_UPD, nbr->peerid, 0,
> > @@ -280,7 +283,8 @@ recv_ls_update(struct nbr *nbr, char *bu
> > }
> > if (nlsa > 0 || len > 0) {
> > log_warnx("recv_ls_update: bad packet size, "
> > - "neighbor ID %s", inet_ntoa(nbr->id));
> > + "neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return;
> > }
> > break;
> > @@ -491,8 +495,8 @@ ls_retrans_timer(int fd, short event, vo
> > if (nlsa == 0) {
> > /* something bad happened retry later */
> > log_warnx("ls_retrans_timer: sending LS update "
> > - "to neighbor ID %s failed",
> > - inet_ntoa(nbr->id));
> > + "to neighbor ID %s (%s) failed",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > TAILQ_REMOVE(&nbr->ls_retrans_list, le, entry);
> > nbr->ls_ret_cnt--;
> > le->le_when = nbr->iface->rxmt_interval;
> > Index: ospfd/neighbor.c
> > ===================================================================
> > RCS file: /cvs/src/usr.sbin/ospfd/neighbor.c,v
> > retrieving revision 1.49
> > diff -u -p -r1.49 neighbor.c
> > --- ospfd/neighbor.c 19 Nov 2019 09:55:55 -0000 1.49
> > +++ ospfd/neighbor.c 2 Nov 2021 17:11:38 -0000
> > @@ -136,9 +136,10 @@ nbr_fsm(struct nbr *nbr, enum nbr_event
> >
> > if (nbr_fsm_tbl[i].state == -1) {
> > /* event outside of the defined fsm, ignore it. */
> > - log_warnx("nbr_fsm: neighbor ID %s, "
> > + log_warnx("nbr_fsm: neighbor ID %s (%s), "
> > "event %s not expected in state %s",
> > - inet_ntoa(nbr->id), nbr_event_names[event],
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr_event_names[event],
> > nbr_state_name(old_state));
> > return (0);
> > }
> > @@ -184,8 +185,9 @@ nbr_fsm(struct nbr *nbr, enum nbr_event
> > }
> >
> > if (ret) {
> > - log_warnx("nbr_fsm: error changing state for neighbor ID %s, "
> > - "event %s, state %s", inet_ntoa(nbr->id),
> > + log_warnx("nbr_fsm: error changing state for neighbor "
> > + "ID %s (%s), event %s, state %s",
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > nbr_event_names[event], nbr_state_name(old_state));
> > return (-1);
> > }
> > @@ -217,10 +219,11 @@ nbr_fsm(struct nbr *nbr, enum nbr_event
> > if_fsm(nbr->iface, IF_EVT_NBR_CHNG);
> >
> > log_debug("nbr_fsm: event %s resulted in action %s and "
> > - "changing state for neighbor ID %s from %s to %s",
> > + "changing state for neighbor ID %s (%s) from %s to %s",
> > nbr_event_names[event],
> > nbr_action_names[nbr_fsm_tbl[i].action],
> > - inet_ntoa(nbr->id), nbr_state_name(old_state),
> > + inet_ntoa(nbr->id), nbr->iface->name,
> > + nbr_state_name(old_state),
> > nbr_state_name(nbr->state));
> >
> > if (nbr->iface->type == IF_TYPE_VIRTUALLINK) {
> > @@ -523,7 +526,8 @@ nbr_act_snapshot(struct nbr *nbr)
> > /* we need to wait for the old snapshot to finish */
> > if (nbr->dd_snapshot) {
> > log_debug("nbr_act_snapshot: giving up, old snapshot running "
> > - "for neigbor ID %s", inet_ntoa(nbr->id));
> > + "for neighbor ID %s (%s)", inet_ntoa(nbr->id),
> > + nbr->iface->name);
> > return (nbr_act_restart_dd(nbr));
> > }
> > ospfe_imsg_compose_rde(IMSG_NEIGHBOR_CAPA, nbr->peerid, 0,
> > @@ -616,8 +620,9 @@ nbr_act_delete(struct nbr *nbr)
> > tv.tv_sec = DEFAULT_NBR_TMOUT;
> >
> > if (evtimer_add(&nbr->inactivity_timer, &tv)) {
> > - log_warnx("nbr_act_delete: error scheduling neighbor ID %s "
> > - "for removal", inet_ntoa(nbr->id));
> > + log_warnx("nbr_act_delete: error scheduling "
> > + "neighbor ID %s (%s) for removal",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> > }
> >
> > return (nbr_act_clear_lists(nbr));
> > @@ -641,7 +646,8 @@ nbr_act_clear_lists(struct nbr *nbr)
> > int
> > nbr_act_hello_check(struct nbr *nbr)
> > {
> > - log_debug("nbr_act_hello_check: neighbor ID %s", inet_ntoa(nbr->id));
> > + log_debug("nbr_act_hello_check: neighbor ID %s (%s)",
> > + inet_ntoa(nbr->id), nbr->iface->name);
> >
> > return (-1);
> > }
> >
>
