On 2022/05/21 17:04, Tobias Heider wrote:
> On Sat, May 21, 2022 at 12:51:19PM +0100, Stuart Henderson wrote:
> > On 2022/05/21 13:44, Tobias Heider wrote:
> > > On Fri, May 20, 2022 at 03:41:12PM +0100, Stuart Henderson wrote:
> > > > I ran into problems with Apple clients failing to connect to
> > > > iked after updating a machine to 7.1, introduced by
> > > > https://github.com/openbsd/src/commit/e3f5cf2ee26929d75dc2df9e86d97c36b2a94268
> > > >
> > > > spi=0xac3d46687441f957: recv IKE_SA_INIT req 0 peer
> > > > rrr.rrr.rrr.rr:49436 local lll.ll.lll.lll:500, 308 bytes, policy
> > > > 'default'
> > > > spi=0xac3d46687441f957: send IKE_SA_INIT res 0 peer
> > > > rrr.rrr.rrr.rr:49436 local lll.ll.lll.lll:500, 341 bytes
> > > > spi=0xac3d46687441f957: recv IKE_AUTH req 1 peer rrr.rrr.rrr.rr:64892
> > > > local lll.ll.lll.lll:4500, 368 bytes, policy 'default'
> > > > policy_test: localid mismatch
> > > > spi=0xac3d46687441f957: ikev2_ike_auth_recv: no compatible policy found
> > > > spi=0xac3d46687441f957: ikev2_send_auth_failed: authentication failed
> > > > for
> > > > spi=0xac3d46687441f957: send IKE_AUTH res 1 peer rrr.rrr.rrr.rr:64892
> > > > local lll.ll.lll.lll:4500, 80 bytes, NAT-T
> > > > spi=0xac3d46687441f957: sa_free: authentication failed
> > > >
> > > > I don't have full details of config done on the other side nor any
> > > > fruit-based phones to test from myself, did anyone already run into this
> > > > and figure out a way around it?
> > >
> > > Hey Stuart,
> > >
> > > I haven't seen this before but I have a theory.
> > > Based on the commit you pointed out the problem is probably the
> > > `dstid kk.kkk.kkk.kkk` line which was ignored before this change.
> > >
> > > This should be easy to check without access to the other device if
> > > you enable verbose logging on your server and look for "ikev2_pld_id"
> > > above the error. I suspect that the ID sent by your apple peer might
> > > actually be a different one than kk.kkk.kkk.kkk.
> > >
> > > Another thing you could try is just removing the dstid part and see
> > > if that works.
> >
> > Oh sorry I wasn't clear about which one the apple was using - the one with
> > "kk.kkk.kkk.kkk" is a lan-to-lan configuration (fixed IP on both endpoints)
> > -
> > the apple is expected to be using the first "from 0.0.0.0/0 to dynamic" one
> > which doesn't have any dstid set, and that's the only one where the IP
> > matches.
>
> Oh, makes sense. I think it may still be related to the IDs, so checking if
> ikev2_pld_id matches what you expect for srcid might be a good start.
> Maybe the apple client is sending something different than
> "xxxxxxxxxxxxxxxxxxxx"
> in their dstid.
I was able to get someone to do a couple of tests (after accidentally updating
that machine and running into the problem again..) - debug log from iked shows
2022-09-21T09:10:44.370Z vpn2 iked[9682]: ikev2_pld_payloads: decrypted payload
IDi nextpayload NOTIFY critical 0x00 length 28
2022-09-21T09:10:44.370Z vpn2 iked[9682]: ikev2_pld_id: id
FQDN/vpn2.xxxxxxxxxxxxxxx length 24
2022-09-21T09:10:44.370Z vpn2 iked[9682]: ikev2_pld_payloads: decrypted payload
NOTIFY nextpayload IDr critical 0x00 length 8
2022-09-21T09:10:44.370Z vpn2 iked[9682]: ikev2_pld_notify: protoid NONE
spisize 0 type INITIAL_CONTACT
2022-09-21T09:10:44.370Z vpn2 iked[9682]: ikev2_pld_payloads: decrypted payload
IDr nextpayload CP critical 0x00 length 12
2022-09-21T09:10:44.370Z vpn2 iked[9682]: ikev2_pld_id: id FQDN/user length 8
...
2022-09-21T09:10:44.371Z vpn2 iked[9682]: ikev2_resp_recv: NAT-T message
received, updated SA
2022-09-21T09:10:44.371Z vpn2 iked[9682]: sa_stateok: SA_INIT flags 0x0000,
require 0x0000
2022-09-21T09:10:44.371Z vpn2 iked[9682]: spi=0xbb3b1aa559598982: sa_state:
SA_INIT -> EAP
2022-09-21T09:10:44.371Z vpn2 iked[9682]: policy_lookup: peerid
'vpn2.xxxxxxxxxxxxxxx'
2022-09-21T09:10:44.371Z vpn2 iked[9682]: policy_lookup: localid 'user'
2022-09-21T09:10:44.372Z vpn2 iked[9682]: policy_test: localid mismatch
2022-09-21T09:10:44.372Z vpn2 iked[9682]: spi=0xbb3b1aa559598982:
ikev2_ike_auth_recv: no compatible policy found
2022-09-21T09:10:44.372Z vpn2 iked[9682]: spi=0xbb3b1aa559598982:
ikev2_send_auth_failed: authentication failed for
Which, given that the apple device is initiator, suggests that they're
sending the IDs the wrong way round. I don't know whether that's a
bug Apple-side or a config issue, either way it's going to be hard
to fix as I don't have access to the client devices (or any similar
device myself to tell them what to change).
Reading policy.c:policy_lookup() ...
125 /* Try to find a matching policy for this message */
126 if ((msg->msg_policy = policy_test(env, &pol)) != NULL) {
127 log_debug("%s: setting policy '%s'", __func__,
128 msg->msg_policy->pol_name);
129 return (0);
130 }
131
132 /* No matching policy found, try the default */
133 if ((msg->msg_policy = env->sc_defaultcon) != NULL)
134 return (0);
So in general iked seems willing to use the default policy if things
don't match up with a specific policy, _but_ now that msg_localid
is set it is checked, and there's no fallback from the mismatch.
Feels like we could do with a way to specify our srcid to send
without forcing a match on the client's IDr (i.e. what used to
happen with iked, and which is what strongswan does), or a way to
fallback if none of our configured policies make it through
policy_test due to "localid mismatch".
I haven't noticed other reports of this. I don't know whether that's
due to nobody else having a config which hits this, or people running
vpn gateways not moving to 7.1 quickly (which wouldn't surprise me),
or whether they've hit it and just not reported...
