search

libreswan / libreswan

libreswan
https://libreswan.org/
Other
851 stars 226 forks source link

Version 5.1: roadwarrior xauth cannot respond to IPsec SA request because no connection is known #1857

Open wmasilva opened 6 days ago

wmasilva commented 6 days ago

What happened?

after update from version 5.0 to version 5.1 cannot establish connection with the error message:

cannot respond to IPsec SA request because no connection is known for 192.168.20.0/24===82.100.127.28[@xauth.mad,MS+XS+S=C]...6.149.27.119[192.168.1.60,+MC+XC+S=C]===192.168.20.2/32

Discussed in the mailing list: https://lists.libreswan.org/archives/list/swan@lists.libreswan.org/thread/SQ2TXV27BNYLQTSPDT77LA2XMOH455BY/

Your configuration

# connection 'remotex_auth'
conn tunnel8-aggr
    aggrmode=yes
    also=tunnel8

conn tunnel8
    pfs=no
    type=tunnel
    auto=add
    ikev2=no
    phase2=esp
    authby=secret
    keyingtries=3
    ikelifetime=24h
    salifetime=24h
    left=82.100.127.28
    leftsubnet=0.0.0.0/0
    leftid=@xauth.mad
    right=%any
    rightid=%any
    rightaddresspool=192.168.20.100-192.168.20.254
    dpddelay=30
    dpdtimeout=300
    dpdaction=clear
    leftxauthserver=yes
    rightxauthclient=yes
    leftmodecfgserver=yes
    rightmodecfgclient=yes
    modecfgpull=yes
    fragmentation=yes
    xauthby=file

# connection 'remote_l2tp'
conn tunnel2-nat
    rightsubnet=vhost:%priv
    also=tunnel2

conn tunnel2
    pfs=no
    type=transport
    auto=add
    ikev2=no
    phase2=esp
    encapsulation=yes
    authby=secret
    keyingtries=3
    ikelifetime=9h
    salifetime=9h
    left=82.100.127.28
    leftprotoport=17/1701
    leftid=@l2tp.mad
    right=%any
    rightprotoport=17/%any
    dpddelay=30
    dpdtimeout=120
    dpdaction=clear

Relevant log output

Oct 18 09:52:07.299981: "tunnel8"[2] 6.149.27.119 #3: the peer proposed: 192.168.20.0/24===192.168.20.100/32
Oct 18 09:52:07.299984: | find_v1_client_connection starting with tunnel8
Oct 18 09:52:07.299989: |   looking for 192.168.20.0/24===192.168.20.100/32
Oct 18 09:52:07.299994: |   concrete checking against sr#0 0.0.0.0/0 -> 192.168.20.100/32
Oct 18 09:52:07.300001: | FOR_EACH_CONNECTION[local=82.100.127.28,remote=6.149.27.119].... in (fc_try() +2025 programs/pluto/ikev1_quick.c)
Oct 18 09:52:07.300005: |   found "tunnel8"[2] 6.149.27.119
Oct 18 09:52:07.300010: |   fc_try: looking at 0.0.0.0/0===192.168.20.100/32
Oct 18 09:52:07.300015: | match_id a=192.168.1.60
Oct 18 09:52:07.300019: |          b=192.168.1.60
Oct 18 09:52:07.300022: | results  matched wildcards=0
Oct 18 09:52:07.300025: | virt: is_virtual_spd_end() no spd=no config=no
Oct 18 09:52:07.300030: | virt: is_virtual_remote() no local/remote spd no/no; config no/no
Oct 18 09:52:07.300035: |   fc_try trying tunnel8:192.168.20.0/24:0/0 -> 192.168.20.100/32:0/0 vs tunnel8:0.0.0.0/0:0/0 -> 192.168.20.100/32:0/0
Oct 18 09:52:07.300039: |    our client (0.0.0.0/0) not in local_net (192.168.20.0/24)
Oct 18 09:52:07.300042: |   matches: 1
Oct 18 09:52:07.300044: |   fc_try concluding with none [0]
Oct 18 09:52:07.300048: |   fc_try tunnel8 gives none
Oct 18 09:52:07.300051: | FOR_EACH_CONNECTION[local=82.100.127.28,remote=<unset-address>].... in (find_v1_client_connection() +2303 programs/pluto/ikev1_quick.c)
Oct 18 09:52:07.300055: |   found "tunnel8"
Oct 18 09:52:07.300058: |   checking hostpair 0.0.0.0/0 -> 192.168.20.100/32
Oct 18 09:52:07.300066: | FOR_EACH_CONNECTION[local=82.100.127.28,remote=<unset-address>].... in (fc_try() +2025 programs/pluto/ikev1_quick.c)
Oct 18 09:52:07.300070: |   found "tunnel8"
Oct 18 09:52:07.300074: |   fc_try: looking at 0.0.0.0/0===0.0.0.0/0
Oct 18 09:52:07.300078: | match_id a=192.168.1.60
Oct 18 09:52:07.300080: |          b=(none)
Oct 18 09:52:07.300084: | results  matched wildcards=15
Oct 18 09:52:07.300087: | virt: is_virtual_spd_end() no spd=no config=no
Oct 18 09:52:07.300091: | virt: is_virtual_remote() no local/remote spd no/no; config no/no
Oct 18 09:52:07.300095: |   fc_try trying tunnel8:192.168.20.0/24:0/0 -> 192.168.20.100/32:0/0 vs tunnel8:0.0.0.0/0:0/0 -> 0.0.0.0/0:0/0
Oct 18 09:52:07.300100: |    our client (0.0.0.0/0) not in local_net (192.168.20.0/24)
Oct 18 09:52:07.300103: |   found "tunnel2"
Oct 18 09:52:07.300105: |   fc_try: looking at <unset-selectors>
Oct 18 09:52:07.300108: |   found "tunnel2-nat"
Oct 18 09:52:07.300111: |   fc_try: looking at <unset-selectors>
Oct 18 09:52:07.300114: |   matches: 3
Oct 18 09:52:07.300116: |   fc_try concluding with none [0]
Oct 18 09:52:07.300119: |   concluding with d = none
Oct 18 09:52:07.300122: | virt: is_virtual_remote() no local/remote spd no/no; config no/no
Oct 18 09:52:07.300127: | virt: is_virtual_spd_end() no spd=no config=no
Oct 18 09:52:07.300134: | virt: is_virtual_spd_end() no spd=no config=no
Oct 18 09:52:07.300137: "tunnel8"[2] 6.149.27.119 #3: cannot respond to IPsec SA request because no connection is known for 192.168.20.0/24===82.100.127.28[@xauth.mad,MS+XS+S=C]...6.149.27.119[192.168.1.60,+MC+XC+S=C]===192.168.20.100/32
Oct 18 09:52:07.300140: | complete v1 state transition with INVALID_ID_INFORMATION
cagney commented 5 days ago

The log contains:

Oct 18 09:52:07.300108: |   found "tunnel2-nat"

which doesn't appear in the config?

wmasilva commented 5 days ago

The log contains:

Oct 18 09:52:07.300108: |   found "tunnel2-nat"

which doesn't appear in the config?

Hi @cagney , i update the config.

cagney commented 5 days ago

@wmasilva tks It shouldn't matter but sometimes a problem can be traced back to the connections and how they are ordered.

cagney commented 3 days ago 
Oct 18 09:52:07.299981: "tunnel8"[2] 6.149.27.119 #3: the peer proposed: 192.168.20.0/24===192.168.20.100/32
Oct 18 09:52:07.299989: |   looking for 192.168.20.0/24===192.168.20.100/32

but then:

Oct 18 09:52:07.299994: |   concrete checking against sr#0 0.0.0.0/0 -> 192.168.20.100/32
Oct 18 09:52:07.300010: |   fc_try: looking at 0.0.0.0/0===192.168.20.100/32

i.e., it's lost one end's selector, likely using spd.client instead of the proposed client

cagney commented 2 days ago

The failing log has:

Oct 17 10:15:01 sol1 pluto[855951]: "tunnel8"[5] 6.149.27.119 #5: responding to Main Mode from unknown peer 6.149.27.119:500
Oct 17 10:15:01 sol1 pluto[855951]: "tunnel8"[5] 6.149.27.119 #5: sent Main Mode R1
Oct 17 10:15:01 sol1 pluto[855951]: "tunnel8"[5] 6.149.27.119 #5: sent Main Mode R2
Oct 17 10:15:01 sol1 pluto[855951]: "tunnel8"[5] 6.149.27.119 #5: Peer ID is ID_IPV4_ADDR: '192.168.1.60'
Oct 17 10:15:01 sol1 pluto[855951]: "tunnel8"[5] 6.149.27.119 #5: switched to "tunnel8"[6] 6.149.27.119
Oct 17 10:15:01 sol1 pluto[855951]: "tunnel8"[5] 6.149.27.119: deleting connection instance with peer 6.149.27.119

which is interesting - the Peer ID is for the client. Does the successful log look the same?

wmasilva commented 2 days ago

Hi @cagney,

It looks the same... 

Oct 25 09:29:26.106120: "tunnel8"[1] 6.149.27.119 #3: responding to Main Mode from unknown peer 6.149.27.119:500
Oct 25 09:29:26.106195: "tunnel8"[1] 6.149.27.119 #3: sent Main Mode R1
Oct 25 09:29:26.148094: "tunnel8"[1] 6.149.27.119 #3: sent Main Mode R2
Oct 25 09:29:26.185039: "tunnel8"[1] 6.149.27.119 #3: Peer ID is ID_IPV4_ADDR: '192.168.1.60'
Oct 25 09:29:26.185079: "tunnel8"[1] 6.149.27.119 #3: switched to "tunnel8"[2] 6.149.27.119
Oct 25 09:29:26.185083: "tunnel8"[1] 6.149.27.119: deleting connection instance with peer 6.149.27.119

Attach a full log with plutodebug=all, when connecting with previous version 5.0.

pluto-5.0.log

cagney commented 1 day ago

Thanks! The old log has this:

Oct 25 09:11:13.420007: |   concluding with d = none
Oct 25 09:11:13.420009: | using something (we hope the IP we or they are NAT'ed to) for transport mode connection "tunnel8"[2] 6.149.27.119
Oct 25 09:11:13.420013: | "tunnel8"[2] 6.149.27.119: addref @0x55aede9a7058(1->2) "tunnel8"[2] 6.149.27.119:  (quick_inI1_outR1_tail() +1110 programs/pluto/ikev1_quick.c)

which was rewritten by 7e82ade3b90f5db636d550b2bb04ddd66686f8de vis:

-   if (nat_traversal_detected(p1st) &&
-       !(p1st->st_policy & POLICY_TUNNEL) &&
-       p == NULL) {
+   /*
+    * For instance: ikev1-l2tp-02 and ikev1-nat-transport-02.
+    */
+   if (p == NULL &&
+       c->config->child_sa.encap_mode == ENCAP_MODE_TRANSPORT &&
+       nat_traversal_detected(p1st)) {
        p = c;
-       connection_buf cib;
-       dbg("using something (we hope the IP we or they are NAT'ed to) for transport mode connection "PRI_CONNECTION"",
-           pri_connection(p, &cib));
+       pdbg(p1st->logger, "using existing connection; nothing better and current is NAT'ed and transport mode");
+   }

the replaced logic !(p1st->st_policy & POLICY_TUNNEL) was the old way of testing for TRANSPORT mode. The config has:

suggesting this was stumbling on when it shouldn't. The find-a-better connection code should have found tunnel8[2].

cagney commented 20 hours ago

More reading. The code in ikev1_quick.c isn't written to handle "narrowing" - it uses selector_range_eq_selector_range() when looking for a better connection (IKEv2 uses selector_in_selector()). This suggests: