[Openswan Users] Problem with Openswan beyond NAT

Rodolfo Giometti giometti at enneenne.com
Mon Oct 14 13:20:30 UTC 2013


Hello,

I need some advice about strange problem...

I'm using openswan 2.6.39 on a system beyond a NAT.

[Ascii art time]

   |         |                    |      |      |          |
   | cisco   |----<<Internet>>----| NAT  |------| openswan |
   | ASR1000 |                    |      |      |          | 

    172.21.59.66            out: 192.168.10.2    10.1.1.50
                            in:  10.1.1.54

After a while communication stops with the following messages on Cisco

*Oct 11 13:34:43.628: %CRYPTO-4-IKMP_BAD_MESSAGE: IKE message from
192.168.10.2    failed its sanity check or is malformed
*Oct 11 13:36:16.072: %CRYPTO-4-RECVD_PKT_INV_SPI: decaps: rec'd IPSEC
packet has invalid spi for destaddr=172.21.59.66, prot=17,
spi=0xC6F485A2(3337913762), srcaddr=192.168.10.2

On my platform pluto doesn't reconize that the comunication to the
peer has throubles and it continues to send ESP and keepalive packets.

In this scenario Cisco attempts to restart the sections on port UDP
500. It seems pluto uses only the port UDP 4500, so the restart message
ISAKMP from Cisco (Identity Protection (Main Mode)) is refused by NAT
because there isn't any replay from pluto in clear text (ICMP from
NAT to Openswan Fails).

Note that it's interesting the fact that, in this scenario, even
unplugging the ethernet cable nothing happens! Otherwise on normal
functioning I get:

pluto[30256]: "selta_0" #1: DPD: No response from peer - declaring
peer dead
pluto[30256]: "selta_0" #1: DPD: Clearing Connection
pluto[30256]: "selta_1" #3: deleting state (STATE_QUICK_I2)
pluto[30256]: "selta_0" #2: deleting state (STATE_QUICK_I2)
pluto[30256]: "selta_0" #1: deleting state (STATE_MAIN_I4)
pluto[30256]: pfkey_lib_debug:pfkey_msg_parse: extension parsing for
type 13(proposal) failed with error -22.
pluto[30256]: pfkey_async: unparseable PF_KEY message: K_SADB_ACQUIRE
len=29, errno=0, seq=2, pid=0; message ignored
pluto[30256]: shutting down
pluto[30256]: forgetting secrets
pluto[30256]: "selta_1": deleting connection
pluto[30256]: "selta_0": deleting connection
pluto[30256]: shutting down interface ipsec0/mrvl2 10.1.1.50:4500
pluto[30256]: shutting down interface ipsec0/mrvl2 10.1.1.50:500
pluto[30284]: pluto_crypto_helper: helper (0) is  normal exiting

Enabling debug=all messages I see:

pluto[30027]: | next event EVENT_NAT_T_KEEPALIVE in 0 seconds
pluto[30027]: | *time to handle event
pluto[30027]: | handling event EVENT_NAT_T_KEEPALIVE
pluto[30027]: | event after this is EVENT_PENDING_DDNS in 11 seconds
pluto[30027]: | processing connection selta_1
pluto[30027]: | processing connection selta_1
pluto[30027]: | ka_event: send NAT-KA to 172.21.59.66:4500 (state=#75)
pluto[30027]: | sending 1 bytes for NAT-T Keep Alive through
mrvl2:4500 to 172.21.59.66:4500 (using #75)
pluto[30027]: |   ff
pluto[30027]: | processing connection selta_0
pluto[30027]: | processing connection selta_0
pluto[30027]: | ka_event: send NAT-KA to 172.21.59.66:4500 (state=#79)
pluto[30027]: | sending 1 bytes for NAT-T Keep Alive through
mrvl2:4500 to 172.21.59.66:4500 (using #79)
pluto[30027]: |   ff
pluto[30027]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20
seconds
pluto[30027]: | event added after event EVENT_PENDING_DDNS
pluto[30027]: | next event EVENT_PENDING_DDNS in 11 seconds
pluto[30027]: |
pluto[30027]: | next event EVENT_PENDING_DDNS in 0 seconds
pluto[30027]: | *time to handle event
pluto[30027]: | handling event EVENT_PENDING_DDNS
pluto[30027]: | event after this is EVENT_NAT_T_KEEPALIVE in 9 seconds
pluto[30027]: | inserting event EVENT_PENDING_DDNS, timeout in 60
seconds
pluto[30027]: | event added after event EVENT_SHUNT_SCAN
pluto[30027]: | next event EVENT_NAT_T_KEEPALIVE in 9 seconds
pluto[30027]: |
pluto[30027]: | next event EVENT_NAT_T_KEEPALIVE in 0 seconds
pluto[30027]: | *time to handle event
pluto[30027]: | handling event EVENT_NAT_T_KEEPALIVE
pluto[30027]: | event after this is EVENT_PENDING_PHASE2 in 50 seconds
pluto[30027]: | processing connection selta_1
pluto[30027]: | processing connection selta_1
pluto[30027]: | ka_event: send NAT-KA to 172.21.59.66:4500 (state=#75)
pluto[30027]: | sending 1 bytes for NAT-T Keep Alive through
mrvl2:4500 to 172.21.59.66:4500 (using #75)
pluto[30027]: |   ff
pluto[30027]: | processing connection selta_0
pluto[30027]: | processing connection selta_0
pluto[30027]: | ka_event: send NAT-KA to 172.21.59.66:4500 (state=#79)
pluto[30027]: | sending 1 bytes for NAT-T Keep Alive through
mrvl2:4500 to 172.21.59.66:4500 (using #79)
pluto[30027]: |   ff
pluto[30027]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20
seconds
pluto[30027]: | event added at head of queue
pluto[30027]: | next event EVENT_NAT_T_KEEPALIVE in 20 seconds

Also output of ipsec whack --status is:

# ipsec whack --status
000 using kernel interface: klips
000 interface ipsec0/mrvl2 10.1.1.50
000 interface ipsec0/mrvl2 10.1.1.50
000 %myid = (none)
000 debug none
000
000 virtual_private (%priv):
000 - allowed 0 subnets:
000 - disallowed 0 subnets:
000 WARNING: Either virtual_private= is not specified, or there is a
syntax
000          error in that line. 'left/rightsubnet=vhost:%priv' will
not work!
000 WARNING: Disallowed subnets in virtual_private= is empty. If you
have
000          private address space in internal use, it should be
excluded!
000
000 algorithm ESP encrypt: id=3, name=ESP_3DES, ivlen=64,
keysizemin=168, keysizemax=168
000 algorithm ESP encrypt: id=12, name=ESP_AES, ivlen=128,
keysizemin=128, keysizemax=256
000 algorithm ESP auth attr: id=1, name=AUTH_ALGORITHM_HMAC_MD5,
keysizemin=128, keysizemax=128
000 algorithm ESP auth attr: id=2, name=AUTH_ALGORITHM_HMAC_SHA1,
keysizemin=160, keysizemax=160
000 algorithm ESP auth attr: id=9, name=AUTH_ALGORITHM_AES_CBC,
keysizemin=128, keysizemax=128
000
000 algorithm IKE encrypt: id=5, name=OAKLEY_3DES_CBC, blocksize=8,
keydeflen=192
000 algorithm IKE encrypt: id=7, name=OAKLEY_AES_CBC, blocksize=16,
keydeflen=128
000 algorithm IKE hash: id=1, name=OAKLEY_MD5, hashsize=16
000 algorithm IKE hash: id=2, name=OAKLEY_SHA1, hashsize=20
000 algorithm IKE hash: id=4, name=OAKLEY_SHA2_256, hashsize=32
000 algorithm IKE hash: id=6, name=OAKLEY_SHA2_512, hashsize=64
000 algorithm IKE dh group: id=2, name=OAKLEY_GROUP_MODP1024,
bits=1024
000 algorithm IKE dh group: id=5, name=OAKLEY_GROUP_MODP1536,
bits=1536
000 algorithm IKE dh group: id=14, name=OAKLEY_GROUP_MODP2048,
bits=2048
000 algorithm IKE dh group: id=15, name=OAKLEY_GROUP_MODP3072,
bits=3072
000 algorithm IKE dh group: id=16, name=OAKLEY_GROUP_MODP4096,
bits=4096
000 algorithm IKE dh group: id=17, name=OAKLEY_GROUP_MODP6144,
bits=6144
000 algorithm IKE dh group: id=18, name=OAKLEY_GROUP_MODP8192,
bits=8192
000 algorithm IKE dh group: id=22, name=OAKLEY_GROUP_DH22, bits=1024
000 algorithm IKE dh group: id=23, name=OAKLEY_GROUP_DH23, bits=2048
000 algorithm IKE dh group: id=24, name=OAKLEY_GROUP_DH24, bits=2048
000
000 stats db_ops: {curr_cnt, total_cnt, maxsz} :context={0,32,36}
trans={0,32,72} attrs={0,32,96}
000
000 "selta_0":
1.1.1.3/32===10.1.1.50<10.1.1.50>...172.21.59.66<172.21.59.66>===1.1.1.254/32;
+erouted; eroute owner: #79
000 "selta_0":     myip=unset; hisip=unset;
000 "selta_0":   ike_life: 3600s; ipsec_life: 28800s; rekey_margin:
540s; rekey_fuzz: 100%;
+keyingtries: 3
000 "selta_0":   policy:
PSK+ENCRYPT+TUNNEL+DONTREKEY+UP+IKEv2ALLOW+SAREFTRACK+lKOD+rKOD; prio:
+32,32; interface: mrvl2;
000 "selta_0":   dpd: action:clear; delay:10; timeout:10;
000 "selta_0":   newest ISAKMP SA: #0; newest IPsec SA: #79;
000 "selta_0":   IKE algorithms wanted:
AES_CBC(7)_256-SHA1(2)_000-MODP1024(2); flags=-strict
000 "selta_0":   IKE algorithms found:
AES_CBC(7)_256-SHA1(2)_160-MODP1024(2)
000 "selta_0":   ESP algorithms wanted: AES(12)_256-SHA1(2)_000;
flags=-strict
000 "selta_0":   ESP algorithms loaded: AES(12)_256-SHA1(2)_160
000 "selta_0":   ESP algorithm newest: AES_256-HMAC_SHA1;
pfsgroup=<N/A>
000 "selta_1":
192.168.2.0/24===10.1.1.50<10.1.1.50>...172.21.59.66<172.21.59.66>===192.168.1.0/24;
+erouted; eroute owner: #75
000 "selta_1":     myip=unset; hisip=unset;
000 "selta_1":   ike_life: 3600s; ipsec_life: 28800s; rekey_margin:
540s; rekey_fuzz: 100%;
+keyingtries: 3
000 "selta_1":   policy:
PSK+ENCRYPT+TUNNEL+DONTREKEY+UP+IKEv2ALLOW+SAREFTRACK+lKOD+rKOD; prio:
+24,24; interface: mrvl2;
000 "selta_1":   dpd: action:clear; delay:10; timeout:10;
000 "selta_1":   newest ISAKMP SA: #0; newest IPsec SA: #75;
000 "selta_1":   IKE algorithms wanted:
AES_CBC(7)_256-SHA1(2)_000-MODP1024(2); flags=-strict
000 "selta_1":   IKE algorithms found:
AES_CBC(7)_256-SHA1(2)_160-MODP1024(2)
000 "selta_1":   ESP algorithms wanted: AES(12)_256-SHA1(2)_000;
flags=-strict
000 "selta_1":   ESP algorithms loaded: AES(12)_256-SHA1(2)_160
000 "selta_1":   ESP algorithm newest: AES_256-HMAC_SHA1;
pfsgroup=<N/A>
000
000 #79: "selta_0":4500 STATE_QUICK_I2 (sent QI2, IPsec SA
established); EVENT_SA_REPLACE_IF_USED in
+14321s; newest IPSEC; eroute owner; isakmp#78; idle; import:admin
initiate
000 #79: "selta_0" used 3146s ago; esp.590e34c4 at 172.21.59.66
esp.79363b80 at 10.1.1.50
+tun.104b at 172.21.59.66 tun.104c at 10.1.1.50 ref=0 refhim=4294901761
000 #75: "selta_1":4500 STATE_QUICK_I2 (sent QI2, IPsec SA
established); EVENT_SA_REPLACE_IF_USED in
+6872s; newest IPSEC; eroute owner; isakmp#74; idle; import:admin
initiate
000 #75: "selta_1" used 3146s ago; esp.1b5f304b at 172.21.59.66
esp.79363b7f at 10.1.1.50
+tun.1049 at 172.21.59.66 tun.104a at 10.1.1.50 ref=0 refhim=4294901761
000

Thanks in advance,

Rodolfo Giometti

-- 

Gnu/Linux Solutions                  e-mail: giometti at enneenne.com
Linux Device Driver                          giometti at linux.it
Embedded Systems                     phone:  +39 349 2432127
UNIX programming                     skype:  rodolfo.giometti
Freelance ICT Italia - Consulente ICT Italia - www.consulenti-ict.it


More information about the Users mailing list