The current log output is not as helpful as i would like it to be, so here's
a diff to make it better. This unifies the syntax of the send and recv output,
uses the same terms as the configuration (peer and local instead of to and from)
and prepends the SAs SPI to each line to make it easier to spot which message
belongs to which flow.
Example old:
ikev2_msg_send: IKE_SA_INIT request from 0.0.0.0:500 to 10.0.1.23:500 msgid 0,
510 bytes
ikev2_recv: IKE_SA_INIT response from responder 10.0.1.23:500 to 10.0.1.24:500
policy 'test' id 0, 446 bytes
ikev2_msg_send: IKE_AUTH request from 10.0.1.24:500 to 10.0.1.23:500 msgid 1,
272 bytes
ikev2_recv: IKE_AUTH response from responder 10.0.1.23:500 to 10.0.1.24:500
policy 'test' id 1, 240 bytes
sa_state: VALID -> ESTABLISHED from 10.0.1.23:500 to 10.0.1.24:500 policy 'test'
Example new:
0x5003cf5b45df23ae: recv IKE_SA_INIT req 0 peer 10.0.1.24:500 local
10.0.1.23:500, 510 bytes, policy 'test'
0x5003cf5b45df23ae: send IKE_SA_INIT res 0 peer 10.0.1.24:500 local
10.0.1.23:500, 446 bytes
0x5003cf5b45df23ae: recv IKE_AUTH req 1 peer 10.0.1.24:500 local 10.0.1.23:500,
272 bytes, policy 'test'
0x5003cf5b45df23ae: send IKE_AUTH res 1 peer 10.0.1.24:500 local 10.0.1.23:500,
240 bytes
0x5003cf5b45df23ae: sa_state: VALID -> ESTABLISHED from 10.0.1.24:500 to
10.0.1.23:500 policy 'test'
Ok?
Index: iked.h
===================================================================
RCS file: /mount/openbsd/cvs/src/sbin/iked/iked.h,v
retrieving revision 1.121
diff -u -p -u -r1.121 iked.h
--- iked.h 11 May 2019 16:30:23 -0000 1.121
+++ iked.h 9 Aug 2019 14:43:33 -0000
@@ -843,6 +843,11 @@ int ikev2_rekey_sa(struct iked *, struc
int ikev2_drop_sa(struct iked *, struct iked_spi *);
int ikev2_print_id(struct iked_id *, char *, size_t);
+const char *ikev2_ikesa_info(uint64_t, const char *msg);
+#define SPI_IH(hdr) ikev2_ikesa_info(betoh64((hdr)->ike_ispi), NULL)
+#define SPI_SH(sh, f) ikev2_ikesa_info((sh)->sh_ispi, (f))
+#define SPI_SA(sa, f) SPI_SH(&(sa)->sa_hdr, (f))
+
/* ikev2_msg.c */
void ikev2_msg_cb(int, short, void *);
struct ibuf *
Index: ikev2.c
===================================================================
RCS file: /mount/openbsd/cvs/src/sbin/iked/ikev2.c,v
retrieving revision 1.171
diff -u -p -u -r1.171 ikev2.c
--- ikev2.c 11 May 2019 16:30:23 -0000 1.171
+++ ikev2.c 9 Aug 2019 15:05:20 -0000
@@ -366,6 +366,20 @@ ikev2_dispatch_cert(int fd, struct privs
return (0);
}
+const char *
+ikev2_ikesa_info(uint64_t spi, const char *msg)
+{
+ static char buf[1024];
+ const char *spistr;
+
+ spistr = print_spi(spi, 8);
+ if (msg)
+ snprintf(buf, sizeof(buf), "%s: %s", spistr, msg);
+ else
+ snprintf(buf, sizeof(buf), "%s: ", spistr);
+ return buf;
+}
+
struct iked_sa *
ikev2_getimsgdata(struct iked *env, struct imsg *imsg, struct iked_sahdr *sh,
uint8_t *type, uint8_t **buf, size_t *size)
@@ -423,14 +437,15 @@ ikev2_recv(struct iked *env, struct iked
if (policy_lookup(env, msg) != 0)
return;
- log_info("%s: %s %s from %s %s to %s policy '%s' id %u, %ld bytes",
- __func__, print_map(hdr->ike_exchange, ikev2_exchange_map),
- msg->msg_response ? "response" : "request",
- initiator ? "responder" : "initiator",
+ log_info("%srecv %s %s %u peer %s local %s, %ld bytes, policy '%s'",
+ SPI_IH(hdr),
+ print_map(hdr->ike_exchange, ikev2_exchange_map),
+ msg->msg_response ? "res" : "req",
+ msg->msg_msgid,
print_host((struct sockaddr *)&msg->msg_peer, NULL, 0),
print_host((struct sockaddr *)&msg->msg_local, NULL, 0),
- msg->msg_policy->pol_name, msg->msg_msgid,
- ibuf_length(msg->msg_data));
+ ibuf_length(msg->msg_data),
+ msg->msg_policy->pol_name);
log_debug("%s: ispi %s rspi %s", __func__,
print_spi(betoh64(hdr->ike_ispi), 8),
print_spi(betoh64(hdr->ike_rspi), 8));
Index: ikev2_msg.c
===================================================================
RCS file: /mount/openbsd/cvs/src/sbin/iked/ikev2_msg.c,v
retrieving revision 1.55
diff -u -p -u -r1.55 ikev2_msg.c
--- ikev2_msg.c 11 May 2019 16:30:23 -0000 1.55
+++ ikev2_msg.c 9 Aug 2019 15:14:23 -0000
@@ -319,12 +319,13 @@ ikev2_msg_send(struct iked *env, struct
exchange = hdr->ike_exchange;
flags = hdr->ike_flags;
- log_info("%s: %s %s from %s to %s msgid %u, %ld bytes%s", __func__,
+ log_info("%ssend %s %s %u peer %s local %s, %ld bytes%s",
+ SPI_IH(hdr),
print_map(exchange, ikev2_exchange_map),
- (flags & IKEV2_FLAG_RESPONSE) ? "response" : "request",
- print_host((struct sockaddr *)&msg->msg_local, NULL, 0),
- print_host((struct sockaddr *)&msg->msg_peer, NULL, 0),
+ (flags & IKEV2_FLAG_RESPONSE) ? "res" : "req",
betoh32(hdr->ike_msgid),
+ print_host((struct sockaddr *)&msg->msg_peer, NULL, 0),
+ print_host((struct sockaddr *)&msg->msg_local, NULL, 0),
ibuf_length(buf), isnatt ? ", NAT-T" : "");
if (isnatt) {
Index: ikev2_pld.c
===================================================================
RCS file: /mount/openbsd/cvs/src/sbin/iked/ikev2_pld.c,v
retrieving revision 1.71
diff -u -p -u -r1.71 ikev2_pld.c
--- ikev2_pld.c 11 May 2019 16:30:23 -0000 1.71
+++ ikev2_pld.c 9 Aug 2019 15:08:33 -0000
@@ -1479,7 +1479,7 @@ ikev2_pld_delete(struct iked *env, struc
}
}
- log_warnx("%s: deleted %zu spis", __func__, found);
+ log_warnx("%s: deleted %zu spis", SPI_SA(sa, __func__), found);
}
if (found) {
Index: policy.c
===================================================================
RCS file: /mount/openbsd/cvs/src/sbin/iked/policy.c,v
retrieving revision 1.47
diff -u -p -u -r1.47 policy.c
--- policy.c 27 Nov 2017 18:39:35 -0000 1.47
+++ policy.c 9 Aug 2019 14:51:21 -0000
@@ -240,14 +240,14 @@ sa_state(struct iked *env, struct iked_s
sa->sa_state = state;
if (ostate != IKEV2_STATE_INIT &&
!sa_stateok(sa, state)) {
- log_debug("%s: cannot switch: %s -> %s", __func__, a, b);
+ log_debug("%s: cannot switch: %s -> %s", SPI_SA(sa, __func__),
a, b);
sa->sa_state = ostate;
} else if (ostate != sa->sa_state) {
switch (state) {
case IKEV2_STATE_ESTABLISHED:
case IKEV2_STATE_CLOSED:
log_info("%s: %s -> %s from %s to %s policy '%s'",
- __func__, a, b,
+ SPI_SA(sa, __func__), a, b,
print_host((struct sockaddr *)&sa->sa_peer.addr,
NULL, 0),
print_host((struct sockaddr *)&sa->sa_local.addr,
