[strongSwan] "unable to add pseudo IPIP SA with SPI c1bb6ffe: Invalid argument"

Lupe Christoph lupe at lupe-christoph.de
Sun Nov 13 15:45:03 CET 2011 

Hi!

I was forced by a buggy openswan port to try StrongSwan on OpenWRT
Backfire 10.03.01 RC6 (pluto did not receive reply packets, if you
care). The server is still using OpenSwan.

But even after a lot of fiddling with settings I can't get StrongSwan to
connect.

Here is the info that hopefully allows somebody who knows StrongSwan
well to tell me what I need to do to get this to work.

I installed these packages (could do a full install for lack of space):

strongswan4 - 4.5.2-1
strongswan4-app-charon - 4.5.2-1
strongswan4-app-pluto - 4.5.2-1
strongswan4-minimal - 4.5.2-1
strongswan4-mod-aes - 4.5.2-1
strongswan4-mod-blowfish - 4.5.2-1
strongswan4-mod-constraints - 4.5.2-1
strongswan4-mod-coupling - 4.5.2-1
strongswan4-mod-des - 4.5.2-1
strongswan4-mod-gmp - 4.5.2-1
strongswan4-mod-hmac - 4.5.2-1
strongswan4-mod-kernel-klips - 4.5.2-1
strongswan4-mod-kernel-netlink - 4.5.2-1
strongswan4-mod-md5 - 4.5.2-1
strongswan4-mod-pem - 4.5.2-1
strongswan4-mod-pkcs1 - 4.5.2-1
strongswan4-mod-pubkey - 4.5.2-1
strongswan4-mod-random - 4.5.2-1
strongswan4-mod-revocation - 4.5.2-1
strongswan4-mod-sha1 - 4.5.2-1
strongswan4-mod-sha2 - 4.5.2-1
strongswan4-mod-socket-default - 4.5.2-1
strongswan4-mod-stroke - 4.5.2-1
strongswan4-mod-updown - 4.5.2-1
strongswan4-mod-x509 - 4.5.2-1
strongswan4-mod-xcbc - 4.5.2-1
strongswan4-utils - 4.5.2-1

===== StrongSwan config =====

config setup
        plutodebug=control
        # crlcheckinterval=600
        # strictcrlpolicy=yes
        # cachecrls=yes
        # nat_traversal=yes
        # charonstart=no
        # plutostart=no
        nat_traversal=yes
        charonstart=yes
        plutostart=yes

conn openswan-server
        auto=add
        authby=rsasig
        keyexchange=ikev1
        right=%defaultroute
        rightsubnet=192.168.1.0/24
        rightcert=/etc/ipsec.d/certs/strongswan-clientCert.pem
        rightsendcert=always
        rightrsasigkey=%cert
        rightid="C=DE, ST=Bavaria, O=My Company, OU=IPSec Clients, CN=strongswan-client.mycompany.de, E=lupe.christoph at mycompany.de"
        left=SERVERIPADDRESS
        leftcert=/etc/ipsec.d/certs/openswan-serverCert.pem
        leftrsasigkey=%cert

===== Openswan config =====

conn strongswan-client
        auto=add
        right=%any
        rightsubnet=192.168.1.0/24
        rightcert=strongswan-clientCert.pem
        rightnexthop=%defaultroute
        left=%defaultroute
        leftcert=openswan-serverCert.pem
        leftsendcert=never

===== Output from ipsec up openswan-server =====
002 "openswan-server" #1: initiating Main Mode
102 "openswan-server" #1: STATE_MAIN_I1: initiate
003 "openswan-server" #1: ignoring Vendor ID payload [4f45517b4f7f6e657a7b4351]
003 "openswan-server" #1: received Vendor ID payload [Dead Peer Detection]
003 "openswan-server" #1: received Vendor ID payload [RFC 3947]
002 "openswan-server" #1: enabling possible NAT-traversal with method 3
104 "openswan-server" #1: STATE_MAIN_I2: sent MI2, expecting MR2
003 "openswan-server" #1: NAT-Traversal: Result using RFC 3947: no NAT detected
002 "openswan-server" #1: we have a cert and are sending it 
106 "openswan-server" #1: STATE_MAIN_I3: sent MI3, expecting MR3
003 "openswan-server" #1: ignoring Vendor ID payload [494b457632]
002 "openswan-server" #1: Peer ID is ID_DER_ASN1_DN: 'C=DE, ST=Bavaria, O=My Company, OU=IPSec Clients, CN=openswan-server.mycompany.de, E=lutz.christoph at mycompany.de'
002 "openswan-server" #1: ISAKMP SA established
004 "openswan-server" #1: STATE_MAIN_I4: ISAKMP SA established
002 "openswan-server" #2: initiating Quick Mode PUBKEY+ENCRYPT+TUNNEL+PFS+UP {using isakmp#1}
110 "openswan-server" #2: STATE_QUICK_I1: initiate
032 "openswan-server" #2: STATE_QUICK_I1: internal error

=== syslog ===

Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | 
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | *received whack message
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | creating state object #1 at 0x49bbe0
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | ICOOKIE:  76 08 08 8a  f4 3c 2b 8a
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | RCOOKIE:  00 00 00 00  00 00 00 00
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | peer:  55 d6 9d b0
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | state hash entry 11
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | Queuing pending Quick Mode with SERVERIPADDRESS "openswan-server"
Nov 13 13:28:43 janus authpriv.warn pluto[28210]: "openswan-server" #1: initiating Main Mode
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | ike proposal: AES_CBC_128/HMAC_SHA1/MODP_2048, 3DES_CBC/HMAC_SHA1/MODP_1536, 
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | 
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | *received 140 bytes from SERVERIPADDRESS:500 on pptp-wan
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | ICOOKIE:  76 08 08 8a  f4 3c 2b 8a
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | RCOOKIE:  0b f2 2e a2  f3 62 65 19
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | peer:  55 d6 9d b0
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | state hash entry 1
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | state object not found
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | ICOOKIE:  76 08 08 8a  f4 3c 2b 8a
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | RCOOKIE:  00 00 00 00  00 00 00 00
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | peer:  55 d6 9d b0
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | state hash entry 11
Nov 13 13:28:43 janus authpriv.debug pluto[28210]: | state object #1 found, in STATE_MAIN_I1
Nov 13 13:28:43 janus authpriv.warn pluto[28210]: "openswan-server" #1: ignoring Vendor ID payload [4f45517b4f7f6e657a7b4351]
Nov 13 13:28:43 janus authpriv.warn pluto[28210]: "openswan-server" #1: received Vendor ID payload [Dead Peer Detection]
Nov 13 13:28:43 janus authpriv.warn pluto[28210]: "openswan-server" #1: received Vendor ID payload [RFC 3947]
Nov 13 13:28:43 janus authpriv.warn pluto[28210]: "openswan-server" #1: enabling possible NAT-traversal with method 3
Nov 13 13:28:44 janus authpriv.debug pluto[28210]: | ICOOKIE:  76 08 08 8a  f4 3c 2b 8a
Nov 13 13:28:44 janus authpriv.debug pluto[28210]: | RCOOKIE:  00 00 00 00  00 00 00 00
Nov 13 13:28:44 janus authpriv.debug pluto[28210]: | peer:  55 d6 9d b0
Nov 13 13:28:44 janus authpriv.debug pluto[28210]: | state hash entry 11
Nov 13 13:28:44 janus authpriv.debug pluto[28210]: | ICOOKIE:  76 08 08 8a  f4 3c 2b 8a
Nov 13 13:28:44 janus authpriv.debug pluto[28210]: | RCOOKIE:  0b f2 2e a2  f3 62 65 19
Nov 13 13:28:44 janus authpriv.debug pluto[28210]: | peer:  55 d6 9d b0
Nov 13 13:28:44 janus authpriv.debug pluto[28210]: | state hash entry 1
Nov 13 13:28:44 janus authpriv.debug pluto[28210]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
Nov 13 13:28:44 janus authpriv.debug pluto[28210]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Nov 13 13:28:45 janus authpriv.debug pluto[28210]: | 
Nov 13 13:28:45 janus authpriv.debug pluto[28210]: | *received 572 bytes from SERVERIPADDRESS:500 on pptp-wan
Nov 13 13:28:45 janus authpriv.debug pluto[28210]: | ICOOKIE:  76 08 08 8a  f4 3c 2b 8a
Nov 13 13:28:45 janus authpriv.debug pluto[28210]: | RCOOKIE:  0b f2 2e a2  f3 62 65 19
Nov 13 13:28:45 janus authpriv.debug pluto[28210]: | peer:  55 d6 9d b0
Nov 13 13:28:45 janus authpriv.debug pluto[28210]: | state hash entry 1
Nov 13 13:28:45 janus authpriv.debug pluto[28210]: | state object #1 found, in STATE_MAIN_I2
Nov 13 13:28:45 janus authpriv.debug pluto[28210]: | requested CA: "C=DE, ST=Bavaria, L=Hintertupfing, O=My Company, OU=IPSec Clients, CN=www.mycompany.de, E=lupe.christoph at mycompany.de"
Nov 13 13:28:46 janus authpriv.warn pluto[28210]: "openswan-server" #1: NAT-Traversal: Result using RFC 3947: no NAT detected
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | our certificate policy is ALWAYS_SEND
Nov 13 13:28:46 janus authpriv.warn pluto[28210]: "openswan-server" #1: we have a cert and are sending it 
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | 
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | *received 380 bytes from SERVERIPADDRESS:500 on pptp-wan
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | ICOOKIE:  76 08 08 8a  f4 3c 2b 8a
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | RCOOKIE:  0b f2 2e a2  f3 62 65 19
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | peer:  55 d6 9d b0
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | state hash entry 1
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | state object #1 found, in STATE_MAIN_I3
Nov 13 13:28:46 janus authpriv.warn pluto[28210]: "openswan-server" #1: ignoring Vendor ID payload [494b457632]
Nov 13 13:28:46 janus authpriv.warn pluto[28210]: "openswan-server" #1: Peer ID is ID_DER_ASN1_DN: 'C=DE, ST=Bavaria, O=My Company, OU=IPSec Clients, CN=openswan-server.mycompany.de, E=lupe.christoph at mycompany.de'
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | RSA signature check passed with keyid d2:0c:0c:4c:e6:32:76:2d:12:66:f2:5f:c9:86:fd:93:1b:ad:83:00
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | peer CA:      "C=DE, ST=Bavaria, L=Hintertupfing, O=My Company, OU=IPSec Clients, CN=www.mycompany.de, E=lupe.christoph at mycompany.de"
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | required CA:  "0\361\255*H\361\255*\230\373\255*\300\372\255*\230\374\255*\374\373\255*|\377\255*|\365\255*\010\221I"
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | inserting event EVENT_SA_REPLACE, timeout in 9807 seconds for #1
Nov 13 13:28:46 janus authpriv.warn pluto[28210]: "openswan-server" #1: ISAKMP SA established
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | unqueuing pending Quick Mode with SERVERIPADDRESS "openswan-server"
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | duplicating state object #1
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | creating state object #2 at 0x49dc78
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | ICOOKIE:  76 08 08 8a  f4 3c 2b 8a
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | RCOOKIE:  0b f2 2e a2  f3 62 65 19
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | peer:  55 d6 9d b0
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | state hash entry 1
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2
Nov 13 13:28:46 janus authpriv.warn pluto[28210]: "openswan-server" #2: initiating Quick Mode PUBKEY+ENCRYPT+TUNNEL+PFS+UP {using isakmp#1}
Nov 13 13:28:46 janus authpriv.debug pluto[28210]: | esp proposal: AES_CBC_128/HMAC_SHA1, 3DES_CBC/HMAC_SHA1, 
Nov 13 13:28:47 janus authpriv.debug pluto[28210]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #2
Nov 13 13:28:47 janus authpriv.debug pluto[28210]: | next event EVENT_RETRANSMIT in 10 seconds for #2
Nov 13 13:28:47 janus authpriv.debug pluto[28210]: | 
Nov 13 13:28:47 janus authpriv.debug pluto[28210]: | *received 428 bytes from SERVERIPADDRESS:500 on pptp-wan
Nov 13 13:28:47 janus authpriv.debug pluto[28210]: | ICOOKIE:  76 08 08 8a  f4 3c 2b 8a
Nov 13 13:28:47 janus authpriv.debug pluto[28210]: | RCOOKIE:  0b f2 2e a2  f3 62 65 19
Nov 13 13:28:47 janus authpriv.debug pluto[28210]: | peer:  55 d6 9d b0
Nov 13 13:28:47 janus authpriv.debug pluto[28210]: | state hash entry 1
Nov 13 13:28:47 janus authpriv.debug pluto[28210]: | state object #2 found, in STATE_QUICK_I1
Nov 13 13:28:49 janus authpriv.debug pluto[28210]: | our client is subnet 192.168.1.0/24
Nov 13 13:28:49 janus authpriv.debug pluto[28210]: | our client protocol/port is 0/0
Nov 13 13:28:49 janus authpriv.debug pluto[28210]: | peer client is SERVERIPADDRESS
Nov 13 13:28:49 janus authpriv.debug pluto[28210]: | peer client protocol/port is 0/0
Nov 13 13:28:49 janus authpriv.debug pluto[28210]: | no valid attribute cert found
Nov 13 13:28:49 janus authpriv.debug pluto[28210]: | kernel_alg_esp_auth_keylen(auth=2, sadb_aalg=3): a_keylen=20
Nov 13 13:28:49 janus authpriv.debug pluto[28210]: | install_ipsec_sa() for #2: inbound and outbound
Nov 13 13:28:49 janus authpriv.debug pluto[28210]: | route owner of "openswan-server" unrouted: NULL; eroute owner: NULL
Nov 13 13:28:49 janus authpriv.info pluto[28210]: unable to add pseudo IPIP SA with SPI c1bb6ffe: Invalid argument (22)
Nov 13 13:28:49 janus authpriv.info pluto[28210]: unable to add SAD entry with SPI c1bb6ffe
Nov 13 13:28:49 janus authpriv.debug pluto[28210]: | state transition function for STATE_QUICK_I1 had internal error
Nov 13 13:28:49 janus authpriv.debug pluto[28210]: | next event EVENT_RETRANSMIT in 8 seconds for #2

Any taker?

Thanks for looking at this.
Lupe Christoph
-- 
| It is a well-known fact in any organisation that, if you want a job    |
| done, you should give it to someone who is already very busy.          |
| Terry Pratchett, "Unseen Academicals"                                  |

More information about the Users mailing list