[Openswan Users] Site-to-site with Cisco ASA5500 tunnel stops passing traffic

[Christopher Opena]

Hello folks,

First post here and have to say I'm loving Openswan so far!  I've
successfully connected with a Juniper box followed by a Cisco ASA 5500
(vendor operated), both of which were fairly seamless affairs.

I'm running into some issues with the Cisco ASA 5500 though, and
unfortunately don't have access to it to watch the logs.  From my own
research I have gathered that:

- tcpdumps from a host on the vendor side of constant ICMP traffic shows
that traffic is halted at 03:46AM (see logs below)
- on my side, ipsec auto --status and /etc/init.d/ipsec status shows that
the tunnels are up

I ran an ipsec barf and the logs from /var/log/messages show some
interesting information, but none from precisely the time that the ICMP
traffic halted (it's all either before or after 03:46):

== /var/log/messages before the traffic stopped passing ==
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
initiating Aggressive Mode #6 to replace #5, connection "conn_cisco_ASA5500/
0x1"
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: pluto_do_crypto: helper (-1) is
 exiting
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: | setting sec: 1
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
received Vendor ID payload [Cisco-Unity]
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
received Vendor ID payload [XAUTH]
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
received Vendor ID payload [Dead Peer Detection]
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] method set
to=106
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
ignoring Vendor ID payload [FRAGMENTATION c0000000]
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
ignoring Vendor ID payload [Cisco VPN 3000 Series]
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
protocol/port in Phase 1 ID Payload must be 0/0 or 17/500 but are 17/0
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
Aggressive mode peer ID is ID_IPV4_ADDR: '1.2.3.4'
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
NAT-Traversal: Result using draft-ietf-ipsec-nat-t-ike-02/03: no NAT
detectedApr 24 03:00:19 ipsec-serv1 pluto[27009]: packet from 1.2.3.4:500:
pluto_do_crypto: helper (-1) is  exiting
Apr 24 03:00:19 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6:
transition from state STATE_AGGR_I1 to state STATE_AGGR_I2Apr 24 03:00:19
ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #6: STATE_AGGR_I2: sent
AI2, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_256
prf=oakley_sha
 group=modp1024}


== /var/log/messages after the traffic stopped passing ==
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
initiating Aggressive Mode #7 to replace #6, connection "conn_cisco_ASA5500/
0x1"
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: pluto_do_crypto: helper (-1) is
 exiting
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: | setting sec: 1
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
received Vendor ID payload [Cisco-Unity]
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
received Vendor ID payload [XAUTH]
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
received Vendor ID payload [Dead Peer Detection]
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] method set
to=106
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
ignoring Vendor ID payload [FRAGMENTATION c0000000]
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
ignoring Vendor ID payload [Cisco VPN 3000 Series]
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
protocol/port in Phase 1 ID Payload must be 0/0 or 17/500 but are 17/0
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
Aggressive mode peer ID is ID_IPV4_ADDR: '1.2.3.4'
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
NAT-Traversal: Result using draft-ietf-ipsec-nat-t-ike-02/03: no NAT
detectedApr 24 03:49:33 ipsec-serv1 pluto[27009]: packet from 1.2.3.4:500:
pluto_do_crypto: helper (-1) is  exiting
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
transition from state STATE_AGGR_I1 to state STATE_AGGR_I2
Apr 24 03:49:33 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
STATE_AGGR_I2: sent AI2, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY
cipher=aes_256 prf=oakley_sha
 group=modp1024}
Apr 24 03:49:34 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
ignoring informational payload, type INVALID_SPI msgid=00000000
Apr 24 03:49:34 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
received and ignored informational message
Apr 24 03:49:40 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
ignoring informational payload, type INVALID_SPI msgid=00000000
Apr 24 03:49:40 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
received and ignored informational message
Apr 24 03:49:46 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
ignoring informational payload, type INVALID_SPI msgid=00000000
Apr 24 03:49:46 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
received and ignored informational message
Apr 24 03:49:52 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
ignoring informational payload, type INVALID_SPI msgid=00000000
Apr 24 03:49:52 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
received and ignored informational message

The messages regarding INVALID_SPI continue at regular intervals for quite
some time afterward, and at 04:34 the standard set of payloads reoccurs
(Cisco-Unity, XAUTH, DPD, FRAGMENTATION, etc.) and finally receives a
Delete SA payload:

Apr 24 04:35:10 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
received and ignored informational message
Apr 24 04:35:10 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #7:
received Delete SA payload: deleting ISAKMP State #7
Apr 24 04:35:10 ipsec-serv1 pluto[27009]: packet from 1.2.3.4:500: received
and ignored informational message
Apr 24 04:35:10 ipsec-serv1 pluto[27009]: "conn_cisco_ASA5500/0x1" #8:
received Delete SA payload: deleting ISAKMP State #8

The tunnel itself comes up quickly and passes traffic for a long time, so
I'm pretty sure there are no issues with the IKE exchange process.  The
actual time from tunnel creation to the point that it stops passing traffic
seems to be intermittent (sometimes 1.5 hrs, sometimes 5) so I'm somewhat
at a loss.  Barring me being able to capture  syslog traffic from the
vendor ASA 5500, has anyone had a similar experience, or suggestions for
where else to look for issues?

Thanks in advance,
-C
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.openswan.org/pipermail/users/attachments/20120424/40aaad6d/attachment.html>