IPSEC Tunnel Goes Down

Hi,

I am having intermittent problems with a IPSEC tunnel going down between two Cisco devices that are in a hub and spoke topology (about 8 spoke devices), it does come back up of its own accord but after almost exactly 1 hour or via a reboot of the spoke device. It only seems to be happening on a 878 router using an SDSL line, I have a number of 837 routers using ADSL which are fine. I have also tried changing the hardware.

Does anybody have any idea why this could be happing or the best way of troubleshooting this sort of problem? I have tried doing a network sniff of the LAN to rule out anything on the LAN, but I cannot see anything suspicious when the link goes down.

Any help would be greatly appreciated.

Thanks

Reply to
Jamie Watson
Loading thread data ...

Jamie,

Enable the following debug:

debug crypto ipsec debug crypto engine debug crypto isakmp ( I think)

When you get the failure, you're gonna have a lot of information about what's going on. You may post this messages here, also.

Regards,

Leandro

Reply to
le_brito

Hi,

I have tried this before but I am going to setup a syslog server to capture the messages and I have a pinger setup so I can pretty much pin point the point of failure to about 5 seconds or so!

Fingers crossed something will show up.

Thanks Jamie

Reply to
Jamie Watson

I hate to recommend the obvious but I've been bit before... Make sure that your remote site doesn't have a power problem that's causing either the router or the DSL modem to reboot. I spent a week troubleshooting a client's problem this past spring. The tunnel between their 506 and their 2811 kept going down, forcing the local sysadmin to reboot one or both devices. I had TAC on the phone for hours at a time. I tried new code, different 506s; I tried everything. We were also the local telco and ISP for this company. We replaced cards in the AFC, upped bandwidth with our providers, scrutinized the config on all our gear, etc. One night something that the local sysadmin said sprung into my mind. He said that they had lots of power problems in their machine shop which is why they had 7-8 UPS in their server room to keep things running. In fact we'd recently sold them a new Liebert. The next day I checked the power cords. Sure enough both the modem and the firewall were powered from the same 250w UPS. I moved these to a different UPS and proceeded to test the old UPS. Sure enough as soon as I pulled the cord from the wall the UPS died. I spent a whole week on a wild goose chase just to find out that a faulty battery was causing the problem.

I believe the power problem had been ongoing for months, maybe even a year. The 506 would boot in about 45 seconds. Few people would notice such a short outage and if they did it would likely be when browsing the web and would be ignored. It wasn't until after the new site came online with the 2811 with a VPN tunnel between both that the problem became apparent. Oddly enough they'd been "experiencing" this problem ever for two weeks which directly corresponded to the amount of time the new site had been online. The tunnel would fix itself in 10-15 minutes or could fix itself if the 2811 was rebooted. My syslog output showed 4-5 reboot per day once I knew what to look for.

I'm sure you've probably already looked into an environmental problem but it never hurts to ask. It's usually the last thing we tend to check and the hardest problems to isolate.

J
Reply to
J

J wrote:

As suggested make sure that the device is not re-booting or crashing. Sh ver shows the uptime.

Look at the log. This will show if the DSL link is flapping unless it has been overwritten or the defaults have been changed.

If it's not the DSL link or other easy problem then start on the crypto debugs.

service timestamps log datetime localtime show-timezone logging buffered 120000 debugging ! Check memory available first no logging console ! Can adversely affect router ntp server x.x.x.x ! Or set the clock yourself if you can't use NTP

n1#sh mem Head Total(b) Used(b) Free(b) Lowest(b) Largest(b) Processor 45167760 170494112 17246060 153248052 150424324

150374444 I/O 3F400000 12582912 5944708 6638204 6638204 6637980 150M Bytes is enough for my logging.

Here is my DSL flapping: I have a Dialer, PPPoA, encrypted GRE tunnel and OSPF, yours may look different.

Jul 7 12:19:46 BST: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to down Jul 7 12:19:46 BST: %DIALER-6-UNBIND: Interface Vi2 unbound from profile Di1 Jul 7 12:19:47 BST: %LINK-3-UPDOWN: Interface ATM0, changed state to down Jul 7 12:19:47 BST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to down Jul 7 12:19:48 BST: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to down Jul 7 12:20:16 BST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel1, changed state to down Jul 7 12:20:16 BST: %OSPF-5-ADJCHG: Process 100, Nbr x.x.x.x on Tunnel1 from FULL to DOWN, Neigh bor Down: Interface down or detached Jul 7 12:20:32 BST: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up Jul 7 12:20:32 BST: %DIALER-6-BIND: Interface Vi2 bound to profile Di1 Jul 7 12:20:33 BST: %LINK-3-UPDOWN: Interface ATM0, changed state to up Jul 7 12:20:34 BST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to up Jul 7 12:20:34 BST: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up Jul 7 12:20:36 BST: %CRYPTO-4-IKMP_NO_SA: IKE message from y.y.y.y has no SA and is not an ini tialization offer Jul 7 12:20:56 BST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Tunnel1, changed state to up Jul 7 12:20:58 BST: %OSPF-5-ADJCHG: Process 100, Nbr x.x.x.x on Tunnel1 from LOADING to FULL, Lo ading Done

Reply to
anybody43

Hi all,

Power is definitely not an issue as they still have internet access and I have confirmed this using a sh ver, funnily enough last night it only went down for about 5 mins and I got the following debug information, can anybody offer any assistance?

Thanks

2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7526: Jul 11 00:34:13.467: IPSEC(sa_request): , 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7527: (key eng. msg.) OUTBOUND local= 81.187.49.119, remote= 194.73.244.238, 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7528: local_proxy= 192.168.117.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7529: remote_proxy= 192.168.115.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7530: protocol= ESP, transform= NONE (Tunnel), 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7531: lifedur= 3600s and 4608000kb, 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7532: spi= 0xAD921828(2912032808), conn_id= 0, keysize= 0, flags= 0x0 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7533: Jul 11 00:34:13.467: ISAKMP: set new node 0 to QM_IDLE 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7534: Jul 11 00:34:13.467: ISAKMP:(2001): sitting IDLE. Starting QM immediately (QM_IDLE ) 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7535: Jul 11 00:34:13.467: ISAKMP:(2001):beginning Quick Mode exchange, M-ID of 993279113 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7536: Jul 11 00:34:13.467: ISAKMP:(2001):QM Initiator gets spi 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7537: Jul 11 00:34:13.467: crypto_engine: Generate IKE hash 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7538: Jul 11 00:34:13.467: crypto_engine: Encrypt IKE packet 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7539: Jul 11 00:34:13.467: ISAKMP:(2001): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7540: Jul 11 00:34:13.471: ISAKMP:(2001):Node 993279113, Input = IKE_MESG_INTERNAL, IKE_INIT_QM 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7541: Jul 11 00:34:13.471: ISAKMP:(2001):Old State = IKE_QM_READY New State = IKE_QM_I_QM1 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7542: Jul 11 00:34:13.495: ISAKMP (0:2001): received packet from 194.73.244.238 dport 500 sport 500 Global (I) QM_IDLE 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7543: Jul 11 00:34:13.495: ISAKMP: set new node 1664178858 to QM_IDLE 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7544: Jul 11 00:34:13.495: crypto_engine: Decrypt IKE packet 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7545: Jul 11 00:34:13.495: crypto_engine: Generate IKE hash 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7546: Jul 11 00:34:13.495: ISAKMP:(2001): processing HASH payload. message ID = 1664178858 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7547: Jul 11 00:34:13.495: ISAKMP:(2001): processing NOTIFY PROPOSAL_NOT_CHOSEN protocol 3 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7548: spi 2912032808, message ID = 1664178858, sa = 8345457C 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7549: Jul 11 00:34:13.495: ISAKMP:(2001): deleting spi 2912032808 message ID = 993279113 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7550: Jul 11 00:34:13.495: ISAKMP:(2001):deleting node 993279113 error TRUE reason "Delete Larval" 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7551: Jul 11 00:34:13.495: ISAKMP:(2001):deleting node 1664178858 error FALSE reason "Informational (in) state 1" 2006-07-11 01:33:15 Local7.Debug 192.168.117.1 7552: Jul 11 00:34:13.499: ISAKMP:(2001):Input = IKE_MESG_FROM_PEER, IKE_INFO_NOTIFY 2006-07-11 01:33:16 Local7.Debug 192.168.117.1 7553: Jul 11 00:34:13.499: ISAKMP:(2001):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE 2006-07-11 01:33:16 Local7.Debug 192.168.117.1 7554: 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7555: Jul 11 00:34:43.455: IPSEC(key_engine): request timer fired: count = 1, 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7556: (identity) local= 81.187.49.119, remote= 194.73.244.238, 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7557: local_proxy= 192.168.117.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7558: remote_proxy= 192.168.115.0/255.255.255.0/0/0 (type=4) 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7559: Jul 11 00:34:43.455: IPSEC(sa_request): , 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7560: (key eng. msg.) OUTBOUND local= 81.187.49.119, remote= 194.73.244.238, 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7561: local_proxy= 192.168.117.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7562: remote_proxy= 192.168.115.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7563: protocol= ESP, transform= NONE (Tunnel), 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7564: lifedur= 3600s and 4608000kb, 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7565: spi= 0xE1EB16DE(3790280414), conn_id= 0, keysize= 0, flags= 0x0 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7566: Jul 11 00:34:43.455: ISAKMP: set new node 0 to QM_IDLE 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7567: Jul 11 00:34:43.455: ISAKMP:(2001): sitting IDLE. Starting QM immediately (QM_IDLE ) 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7568: Jul 11 00:34:43.455: ISAKMP:(2001):beginning Quick Mode exchange, M-ID of 1517037910 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7569: Jul 11 00:34:43.455: ISAKMP:(2001):QM Initiator gets spi 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7570: Jul 11 00:34:43.455: crypto_engine: Generate IKE hash 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7571: Jul 11 00:34:43.455: crypto_engine: Encrypt IKE packet 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7572: Jul 11 00:34:43.459: ISAKMP:(2001): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7573: Jul 11 00:34:43.459: ISAKMP:(2001):Node 1517037910, Input = IKE_MESG_INTERNAL, IKE_INIT_QM 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7574: Jul 11 00:34:43.459: ISAKMP:(2001):Old State = IKE_QM_READY New State = IKE_QM_I_QM1 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7575: Jul 11 00:34:43.483: ISAKMP (0:2001): received packet from 194.73.244.238 dport 500 sport 500 Global (I) QM_IDLE 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7576: Jul 11 00:34:43.483: ISAKMP: set new node 900690647 to QM_IDLE 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7577: Jul 11 00:34:43.483: crypto_engine: Decrypt IKE packet 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7578: Jul 11 00:34:43.483: crypto_engine: Generate IKE hash 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7579: Jul 11 00:34:43.487: ISAKMP:(2001): processing HASH payload. message ID = 900690647 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7580: Jul 11 00:34:43.487: ISAKMP:(2001): processing NOTIFY PROPOSAL_NOT_CHOSEN protocol 3 2006-07-11 01:33:45 Local7.Debug 192.168.117.1 7581: spi 3790280414, message ID = 900690647, sa = 8345457C 2006-07-11 01:33:46 Local7.Debug 192.168.117.1 7582: Jul 11 00:34:43.487: ISAKMP:(2001): deleting spi 3790280414 message ID = 1517037910 2006-07-11 01:33:46 Local7.Debug 192.168.117.1 7583: Jul 11 00:34:43.487: ISAKMP:(2001):deleting node 1517037910 error TRUE reason "Delete Larval" 2006-07-11 01:33:46 Local7.Debug 192.168.117.1 7584: Jul 11 00:34:43.487: ISAKMP:(2001):deleting node 900690647 error FALSE reason "Informational (in) state 1" 2006-07-11 01:33:46 Local7.Debug 192.168.117.1 7585: Jul 11 00:34:43.487: ISAKMP:(2001):Input = IKE_MESG_FROM_PEER, IKE_INFO_NOTIFY 2006-07-11 01:33:46 Local7.Debug 192.168.117.1 7586: Jul 11 00:34:43.487: ISAKMP:(2001):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE 2006-07-11 01:33:46 Local7.Debug 192.168.117.1 7587: 2006-07-11 01:34:06 Local7.Debug 192.168.117.1 7588: Jul 11 00:35:03.481: ISAKMP:(2001):purging node 993279113 2006-07-11 01:34:06 Local7.Debug 192.168.117.1 7589: Jul 11 00:35:03.485: ISAKMP:(2001):purging node 1664178858 2006-07-11 01:34:16 Local7.Debug 192.168.117.1 7590: Jul 11 00:35:13.446: IPSEC(key_engine): request timer fired: count = 2, 2006-07-11 01:34:16 Local7.Debug 192.168.117.1 7591: (identity) local= 81.187.49.119, remote= 194.73.244.238, 2006-07-11 01:34:16 Local7.Debug 192.168.117.1 7592: local_proxy= 192.168.117.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:34:16 Local7.Debug 192.168.117.1 7593: remote_proxy= 192.168.115.0/255.255.255.0/0/0 (type=4) 2006-07-11 01:34:36 Local7.Debug 192.168.117.1 7594: Jul 11 00:35:33.473: ISAKMP:(2001):purging node 1517037910 2006-07-11 01:34:36 Local7.Debug 192.168.117.1 7595: Jul 11 00:35:33.473: ISAKMP:(2001):purging node 900690647 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7596: Jul 11 00:39:13.479: IPSEC(sa_request): , 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7597: (key eng. msg.) OUTBOUND local= 81.187.49.119, remote= 194.73.244.238, 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7598: local_proxy= 192.168.117.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7599: remote_proxy= 192.168.115.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7600: protocol= ESP, transform= NONE (Tunnel), 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7601: lifedur= 3600s and 4608000kb, 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7602: spi= 0x2A81CD3C(713149756), conn_id= 0, keysize= 0, flags= 0x0 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7603: Jul 11 00:39:13.483: ISAKMP: set new node 0 to QM_IDLE 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7604: Jul 11 00:39:13.483: ISAKMP:(2001): sitting IDLE. Starting QM immediately (QM_IDLE ) 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7605: Jul 11 00:39:13.483: ISAKMP:(2001):beginning Quick Mode exchange, M-ID of -2110321901 2006-07-11 01:38:15 Local7.Debug 192.168.117.1 7606: Jul 11 00:39:13.483: ISAKMP:(2001):QM Initiator gets spi 2006-07-11 01:38:16 Local7.Debug 192.168.117.1 7607: Jul 11 00:39:13.483: crypto_engine: Generate IKE hash 2006-07-11 01:38:16 Local7.Debug 192.168.117.1 7608: Jul 11 00:39:13.483: crypto_engine: Encrypt IKE packet 2006-07-11 01:38:16 Local7.Debug 192.168.117.1 7609: Jul 11 00:39:13.483: ISAKMP:(2001): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:38:16 Local7.Debug 192.168.117.1 7610: Jul 11 00:39:13.483: ISAKMP:(2001):Node -2110321901, Input = IKE_MESG_INTERNAL, IKE_INIT_QM 2006-07-11 01:38:16 Local7.Debug 192.168.117.1 7611: Jul 11 00:39:13.483: ISAKMP:(2001):Old State = IKE_QM_READY New State = IKE_QM_I_QM1 2006-07-11 01:38:26 Local7.Debug 192.168.117.1 7612: Jul 11 00:39:23.480: ISAKMP:(2001): retransmitting phase 2 QM_IDLE -2110321901 ... 2006-07-11 01:38:26 Local7.Debug 192.168.117.1 7613: Jul 11 00:39:23.480: ISAKMP (0:2001): incrementing error counter on node, attempt 1 of 5: retransmit phase 2 2006-07-11 01:38:26 Local7.Debug 192.168.117.1 7614: Jul 11 00:39:23.480: ISAKMP (0:2001): incrementing error counter on sa, attempt 1 of 5: retransmit phase 2 2006-07-11 01:38:26 Local7.Debug 192.168.117.1 7615: Jul 11 00:39:23.480: ISAKMP:(2001): retransmitting phase 2 -2110321901 QM_IDLE 2006-07-11 01:38:26 Local7.Debug 192.168.117.1 7616: Jul 11 00:39:23.480: ISAKMP:(2001): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:38:36 Local7.Debug 192.168.117.1 7617: Jul 11 00:39:33.477: ISAKMP:(2001): retransmitting phase 2 QM_IDLE -2110321901 ... 2006-07-11 01:38:36 Local7.Debug 192.168.117.1 7618: Jul 11 00:39:33.477: ISAKMP (0:2001): incrementing error counter on node, attempt 2 of 5: retransmit phase 2 2006-07-11 01:38:36 Local7.Debug 192.168.117.1 7619: Jul 11 00:39:33.477: ISAKMP (0:2001): incrementing error counter on sa, attempt 2 of 5: retransmit phase 2 2006-07-11 01:38:36 Local7.Debug 192.168.117.1 7620: Jul 11 00:39:33.477: ISAKMP:(2001): retransmitting phase 2 -2110321901 QM_IDLE 2006-07-11 01:38:36 Local7.Debug 192.168.117.1 7621: Jul 11 00:39:33.477: ISAKMP:(2001): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7622: Jul 11 00:39:43.471: IPSEC(key_engine): request timer fired: count = 1, 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7623: (identity) local= 81.187.49.119, remote= 194.73.244.238, 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7624: local_proxy= 192.168.117.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7625: remote_proxy= 192.168.115.0/255.255.255.0/0/0 (type=4) 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7626: Jul 11 00:39:43.471: IPSEC(sa_request): , 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7627: (key eng. msg.) OUTBOUND local= 81.187.49.119, remote= 194.73.244.238, 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7628: local_proxy= 192.168.117.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7629: remote_proxy= 192.168.115.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7630: protocol= ESP, transform= NONE (Tunnel), 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7631: lifedur= 3600s and 4608000kb, 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7632: spi= 0x1D9F2CB5(496970933), conn_id= 0, keysize= 0, flags= 0x0 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7633: Jul 11 00:39:43.471: ISAKMP: set new node 0 to QM_IDLE 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7634: Jul 11 00:39:43.471: ISAKMP:(2001): sitting IDLE. Starting QM immediately (QM_IDLE ) 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7635: Jul 11 00:39:43.471: ISAKMP:(2001):beginning Quick Mode exchange, M-ID of -16906459 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7636: Jul 11 00:39:43.471: ISAKMP:(2001):QM Initiator gets spi 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7637: Jul 11 00:39:43.471: crypto_engine: Generate IKE hash 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7638: Jul 11 00:39:43.471: crypto_engine: Encrypt IKE packet 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7639: Jul 11 00:39:43.475: ISAKMP:(2001): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:38:45 Local7.Debug 192.168.117.1 7640: Jul 11 00:39:43.475: ISAKMP:(2001):Node -16906459, Input = IKE_MESG_INTERNAL, IKE_INIT_QM 2006-07-11 01:38:46 Local7.Debug 192.168.117.1 7641: Jul 11 00:39:43.475: ISAKMP:(2001):Old State = IKE_QM_READY New State = IKE_QM_I_QM1 2006-07-11 01:38:46 Local7.Debug 192.168.117.1 7642: Jul 11 00:39:43.475: ISAKMP:(2001): retransmitting phase 2 QM_IDLE -2110321901 ... 2006-07-11 01:38:46 Local7.Debug 192.168.117.1 7643: Jul 11 00:39:43.475: ISAKMP (0:2001): incrementing error counter on node, attempt 3 of 5: retransmit phase 2 2006-07-11 01:38:46 Local7.Debug 192.168.117.1 7644: Jul 11 00:39:43.475: ISAKMP (0:2001): incrementing error counter on sa, attempt 3 of 5: retransmit phase 2 2006-07-11 01:38:46 Local7.Debug 192.168.117.1 7645: Jul 11 00:39:43.475: ISAKMP:(2001): retransmitting phase 2 -2110321901 QM_IDLE 2006-07-11 01:38:46 Local7.Debug 192.168.117.1 7646: Jul 11 00:39:43.475: ISAKMP:(2001): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:38:55 Local7.Debug 192.168.117.1 7647: Jul 11 00:39:53.472: ISAKMP:(2001): retransmitting phase 2 QM_IDLE -16906459 ... 2006-07-11 01:38:55 Local7.Debug 192.168.117.1 7648: Jul 11 00:39:53.472: ISAKMP (0:2001): incrementing error counter on node, attempt 1 of 5: retransmit phase 2 2006-07-11 01:38:55 Local7.Debug 192.168.117.1 7649: Jul 11 00:39:53.472: ISAKMP (0:2001): incrementing error counter on sa, attempt 4 of 5: retransmit phase 2 2006-07-11 01:38:55 Local7.Debug 192.168.117.1 7650: Jul 11 00:39:53.472: ISAKMP:(2001): retransmitting phase 2 -16906459 QM_IDLE 2006-07-11 01:38:55 Local7.Debug 192.168.117.1 7651: Jul 11 00:39:53.472: ISAKMP:(2001): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:38:55 Local7.Debug 192.168.117.1 7652: Jul 11 00:39:53.472: ISAKMP:(2001): retransmitting phase 2 QM_IDLE -2110321901 ... 2006-07-11 01:38:56 Local7.Debug 192.168.117.1 7653: Jul 11 00:39:53.472: ISAKMP (0:2001): incrementing error counter on node, attempt 4 of 5: retransmit phase 2 2006-07-11 01:38:56 Local7.Debug 192.168.117.1 7654: Jul 11 00:39:53.472: ISAKMP (0:2001): incrementing error counter on sa, attempt 5 of 5: retransmit phase 2 2006-07-11 01:38:56 Local7.Debug 192.168.117.1 7655: Jul 11 00:39:53.472: ISAKMP:(2001): retransmitting phase 2 -2110321901 QM_IDLE 2006-07-11 01:38:56 Local7.Debug 192.168.117.1 7656: Jul 11 00:39:53.472: ISAKMP:(2001): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7657: Jul 11 00:40:03.469: ISAKMP:(2001): retransmitting phase 2 QM_IDLE -16906459 ... 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7658: Jul 11 00:40:03.469: ISAKMP:(2001):peer does not do paranoid keepalives. 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7659: 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7660: Jul 11 00:40:03.469: ISAKMP:(2001):deleting SA reason "Death by retransmission P2" state (I) QM_IDLE (peer 194.73.244.238) 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7661: Jul 11 00:40:03.469: ISAKMP:(2001): retransmitting phase 2 QM_IDLE -2110321901 ... 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7662: Jul 11 00:40:03.469: ISAKMP:(2001):peer does not do paranoid keepalives. 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7663: 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7664: Jul 11 00:40:03.469: ISAKMP: set new node 1451332553 to QM_IDLE 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7665: Jul 11 00:40:03.469: crypto_engine: Generate IKE hash 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7666: Jul 11 00:40:03.469: crypto_engine: Encrypt IKE packet 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7667: Jul 11 00:40:03.469: ISAKMP:(2001): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7668: Jul 11 00:40:03.469: ISAKMP:(2001):purging node 1451332553 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7669: Jul 11 00:40:03.469: ISAKMP:(2001):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7670: Jul 11 00:40:03.473: ISAKMP:(2001):Old State = IKE_P1_COMPLETE New State = IKE_DEST_SA 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7671: 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7672: Jul 11 00:40:03.473: ISAKMP:(2001):deleting SA reason "No reason" state (I) QM_IDLE (peer 194.73.244.238) 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7673: Jul 11 00:40:03.473: ISAKMP: Unlocking peer struct 0x8376EDF0 for isadb_mark_sa_deleted(), count 0 2006-07-11 01:39:05 Local7.Debug 192.168.117.1 7674: Jul 11 00:40:03.477: ISAKMP:(2001):deleting node -2110321901 error FALSE reason "IKE deleted" 2006-07-11 01:39:06 Local7.Debug 192.168.117.1 7675: Jul 11 00:40:03.477: ISAKMP:(2001):deleting node -16906459 error FALSE reason "IKE deleted" 2006-07-11 01:39:06 Local7.Debug 192.168.117.1 7676: Jul 11 00:40:03.477: crypto engine: deleting IKE SA SW:1 2006-07-11 01:39:06 Local7.Debug 192.168.117.1 7677: Jul 11 00:40:03.477: crypto_engine: Delete IKE SA 2006-07-11 01:39:06 Local7.Debug 192.168.117.1 7678: Jul 11 00:40:03.477: ISAKMP:(2001):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH 2006-07-11 01:39:06 Local7.Debug 192.168.117.1 7679: Jul 11 00:40:03.477: ISAKMP:(2001):Old State = IKE_DEST_SA New State = IKE_DEST_SA 2006-07-11 01:39:06 Local7.Debug 192.168.117.1 7680: 2006-07-11 01:39:16 Local7.Debug 192.168.117.1 7681: Jul 11 00:40:13.462: IPSEC(key_engine): request timer fired: count = 2, 2006-07-11 01:39:16 Local7.Debug 192.168.117.1 7682: (identity) local= 81.187.49.119, remote= 194.73.244.238, 2006-07-11 01:39:16 Local7.Debug 192.168.117.1 7683: local_proxy= 192.168.117.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:39:16 Local7.Debug 192.168.117.1 7684: remote_proxy= 192.168.115.0/255.255.255.0/0/0 (type=4) 2006-07-11 01:39:56 Local7.Debug 192.168.117.1 7685: Jul 11 00:40:53.463: ISAKMP:(2001):purging node -2110321901 2006-07-11 01:39:56 Local7.Debug 192.168.117.1 7686: Jul 11 00:40:53.463: ISAKMP:(2001):purging node -16906459 2006-07-11 01:40:06 Local7.Debug 192.168.117.1 7687: Jul 11 00:41:03.460: ISAKMP:(2001):purging SA., sa=8345457C, delme=8345457C 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7688: Jul 11 00:44:13.499: IPSEC(sa_request): , 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7689: (key eng. msg.) OUTBOUND local= 81.187.49.119, remote= 194.73.244.238, 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7690: local_proxy= 192.168.117.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7691: remote_proxy= 192.168.115.0/255.255.255.0/0/0 (type=4), 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7692: protocol= ESP, transform= NONE (Tunnel), 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7693: lifedur= 3600s and 4608000kb, 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7694: spi= 0x781C4775(2015119221), conn_id= 0, keysize= 0, flags= 0x0 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7695: Jul 11 00:44:13.499: ISAKMP:(0): SA request profile is (NULL) 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7696: Jul 11 00:44:13.499: ISAKMP: Found a peer struct for 194.73.244.238, peer port 500 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7697: Jul 11 00:44:13.499: ISAKMP: Locking peer struct 0x8376EDF0, refcount 1 for isakmp_initiator 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7698: Jul 11 00:44:13.499: ISAKMP: local port 500, remote port 500 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7699: Jul 11 00:44:13.499: ISAKMP: set new node 0 to QM_IDLE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7700: Jul 11 00:44:13.499: insert sa successfully sa = 847C999C 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7701: Jul 11 00:44:13.499: ISAKMP:(0):Can not start Aggressive mode, trying Main mode. 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7702: Jul 11 00:44:13.499: ISAKMP:(0):found peer pre-shared key matching 194.73.244.238 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7703: Jul 11 00:44:13.499: ISAKMP:(0): constructed NAT-T vendor-07 ID 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7704: Jul 11 00:44:13.499: ISAKMP:(0): constructed NAT-T vendor-03 ID 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7705: Jul 11 00:44:13.499: ISAKMP:(0): constructed NAT-T vendor-02 ID 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7706: Jul 11 00:44:13.499: ISAKMP:(0):Input = IKE_MESG_FROM_IPSEC, IKE_SA_REQ_MM 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7707: Jul 11 00:44:13.499: ISAKMP:(0):Old State = IKE_READY New State = IKE_I_MM1 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7708: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7709: Jul 11 00:44:13.499: ISAKMP:(0): beginning Main Mode exchange 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7710: Jul 11 00:44:13.503: ISAKMP:(0): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) MM_NO_STATE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7711: Jul 11 00:44:13.527: ISAKMP (0:0): received packet from 194.73.244.238 dport 500 sport 500 Global (I) MM_NO_STATE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7712: Jul 11 00:44:13.527: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7713: Jul 11 00:44:13.527: ISAKMP:(0):Old State = IKE_I_MM1 New State = IKE_I_MM2 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7714: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7715: Jul 11 00:44:13.531: ISAKMP:(0): processing SA payload. message ID = 0 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7716: Jul 11 00:44:13.531: ISAKMP:(0): processing vendor id payload 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7717: Jul 11 00:44:13.531: ISAKMP:(0): vendor ID seems Unity/DPD but major 245 mismatch 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7718: Jul 11 00:44:13.531: ISAKMP (0:0): vendor ID is NAT-T v7 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7719: Jul 11 00:44:13.531: ISAKMP:(0):found peer pre-shared key matching 194.73.244.238 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7720: Jul 11 00:44:13.531: ISAKMP:(0): local preshared key found 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7721: Jul 11 00:44:13.531: ISAKMP : Scanning profiles for xauth ... 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7722: Jul 11 00:44:13.531: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7723: Jul 11 00:44:13.531: ISAKMP: encryption DES-CBC 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7724: Jul 11 00:44:13.531: ISAKMP: hash MD5 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7725: Jul 11 00:44:13.531: ISAKMP: default group 1 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7726: Jul 11 00:44:13.531: ISAKMP: auth pre-share 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7727: Jul 11 00:44:13.531: ISAKMP: life type in seconds 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7728: Jul 11 00:44:13.531: ISAKMP: life duration (VPI) of 0x0 0x1 0x51 0x80 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7729: Jul 11 00:44:13.531: ISAKMP:(0):atts are acceptable. Next payload is 0 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7730: Jul 11 00:44:13.531: ISAKMP:(0): processing vendor id payload 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7731: Jul 11 00:44:13.531: ISAKMP:(0): vendor ID seems Unity/DPD but major 245 mismatch 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7732: Jul 11 00:44:13.531: ISAKMP (0:0): vendor ID is NAT-T v7 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7733: Jul 11 00:44:13.531: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7734: Jul 11 00:44:13.531: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM2 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7735: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7736: Jul 11 00:44:13.535: ISAKMP:(0): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) MM_SA_SETUP 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7737: Jul 11 00:44:13.535: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7738: Jul 11 00:44:13.535: ISAKMP:(0):Old State = IKE_I_MM2 New State = IKE_I_MM3 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7739: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7740: Jul 11 00:44:13.567: ISAKMP (0:0): received packet from 194.73.244.238 dport 500 sport 500 Global (I) MM_SA_SETUP 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7741: Jul 11 00:44:13.567: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7742: Jul 11 00:44:13.567: ISAKMP:(0):Old State = IKE_I_MM3 New State = IKE_I_MM4 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7743: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7744: Jul 11 00:44:13.567: ISAKMP:(0): processing KE payload. message ID = 0 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7745: Jul 11 00:44:13.567: crypto_engine: Create DH shared secret 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7746: Jul 11 00:44:13.567: crypto_engine: Modular Exponentiation 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7747: Jul 11 00:44:13.571: ISAKMP:(0): processing NONCE payload. message ID = 0 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7748: Jul 11 00:44:13.571: ISAKMP:(0):found peer pre-shared key matching 194.73.244.238 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7749: Jul 11 00:44:13.575: crypto_engine: Create IKE SA 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7750: Jul 11 00:44:13.575: crypto engine: deleting DH phase 2 SW:7 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7751: Jul 11 00:44:13.575: crypto_engine: Delete DH shared secret 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7752: Jul 11 00:44:13.575: ISAKMP:(2002): processing vendor id payload 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7753: Jul 11 00:44:13.575: ISAKMP:(2002): vendor ID is Unity 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7754: Jul 11 00:44:13.575: ISAKMP:(2002): processing vendor id payload 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7755: Jul 11 00:44:13.575: ISAKMP:(2002): vendor ID is DPD 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7756: Jul 11 00:44:13.575: ISAKMP:(2002): processing vendor id payload 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7757: Jul 11 00:44:13.575: ISAKMP:(2002): speaking to another IOS box! 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7758: Jul 11 00:44:13.575: ISAKMP:(2002):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7759: Jul 11 00:44:13.575: ISAKMP:(2002):Old State = IKE_I_MM4 New State = IKE_I_MM4 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7760: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7761: Jul 11 00:44:13.575: ISAKMP:(2002):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7762: Jul 11 00:44:13.575: ISAKMP (0:2002): ID payload 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7763: next-payload : 8 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7764: type : 1 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7765: address : 81.187.49.119 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7766: protocol : 17 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7767: port : 500 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7768: length : 12 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7769: Jul 11 00:44:13.579: ISAKMP:(2002):Total payload length: 12 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7770: Jul 11 00:44:13.579: crypto_engine: Generate IKE hash 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7771: Jul 11 00:44:13.579: crypto_engine: Encrypt IKE packet 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7772: Jul 11 00:44:13.579: ISAKMP:(2002): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) MM_KEY_EXCH 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7773: Jul 11 00:44:13.579: ISAKMP:(2002):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7774: Jul 11 00:44:13.579: ISAKMP:(2002):Old State = IKE_I_MM4 New State = IKE_I_MM5 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7775: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7776: Jul 11 00:44:13.603: ISAKMP (0:2002): received packet from 194.73.244.238 dport 500 sport 500 Global (I) MM_KEY_EXCH 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7777: Jul 11 00:44:13.603: crypto_engine: Decrypt IKE packet 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7778: Jul 11 00:44:13.603: ISAKMP:(2002): processing ID payload. message ID = 0 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7779: Jul 11 00:44:13.603: ISAKMP (0:2002): ID payload 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7780: next-payload : 8 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7781: type : 1 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7782: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7783: address : 194.73.244.238 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7784: protocol : 17 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7785: port : 500 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7786: length : 12 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7787: Jul 11 00:44:13.603: ISAKMP:(0):: peer matches *none* of the profiles 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7788: Jul 11 00:44:13.603: ISAKMP:(2002): processing HASH payload. message ID = 0 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7789: Jul 11 00:44:13.603: crypto_engine: Generate IKE hash 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7790: Jul 11 00:44:13.603: ISAKMP:(2002):SA authentication status: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7791: authenticated 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7792: Jul 11 00:44:13.607: ISAKMP:(2002):SA has been authenticated with 194.73.244.238 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7793: Jul 11 00:44:13.607: ISAKMP:(2002):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7794: Jul 11 00:44:13.607: ISAKMP:(2002):Old State = IKE_I_MM5 New State = IKE_I_MM6 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7795: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7796: Jul 11 00:44:13.607: ISAKMP:(2002):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7797: Jul 11 00:44:13.607: ISAKMP:(2002):Old State = IKE_I_MM6 New State = IKE_I_MM6 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7798: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7799: Jul 11 00:44:13.607: ISAKMP:(2002):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7800: Jul 11 00:44:13.607: ISAKMP:(2002):Old State = IKE_I_MM6 New State = IKE_P1_COMPLETE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7801: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7802: Jul 11 00:44:13.607: ISAKMP:(2002):beginning Quick Mode exchange, M-ID of 1636298356 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7803: Jul 11 00:44:13.611: ISAKMP:(2002):QM Initiator gets spi 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7804: Jul 11 00:44:13.611: crypto_engine: Generate IKE hash 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7805: Jul 11 00:44:13.611: crypto_engine: Encrypt IKE packet 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7806: Jul 11 00:44:13.611: ISAKMP:(2002): sending packet to 194.73.244.238 my_port 500 peer_port 500 (I) QM_IDLE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7807: Jul 11 00:44:13.611: ISAKMP:(2002):Node 1636298356, Input = IKE_MESG_INTERNAL, IKE_INIT_QM 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7808: Jul 11 00:44:13.611: ISAKMP:(2002):Old State = IKE_QM_READY New State = IKE_QM_I_QM1 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7809: Jul 11 00:44:13.611: ISAKMP:(2002):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7810: Jul 11 00:44:13.611: ISAKMP:(2002):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7811: 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7812: Jul 11 00:44:13.639: ISAKMP (0:2002): received packet from 194.73.244.238 dport 500 sport 500 Global (I) QM_IDLE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7813: Jul 11 00:44:13.639: ISAKMP: set new node 140515692 to QM_IDLE 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7814: Jul 11 00:44:13.639: crypto_engine: Decrypt IKE packet 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7815: Jul 11 00:44:13.639: crypto_engine: Generate IKE hash 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7816: Jul 11 00:44:13.639: ISAKMP:(2002): processing HASH payload. message ID = 140515692 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7817: Jul 11 00:44:13.639: ISAKMP:(2002): processing NOTIFY PROPOSAL_NOT_CHOSEN protocol 3 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7818: spi 2015119221, message ID = 140515692, sa = 847C999C 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7819: Jul 11 00:44:13.639: ISAKMP:(2002): deleting spi 2015119221 message ID = 1636298356 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7820: Jul 11 00:44:13.639: ISAKMP:(2002):deleting node 1636298356 error TRUE reason "Delete Larval" 2006-07-11 01:43:15 Local7.Debug 192.168.117.1 7821: Jul 11 00:44:13.639: ISAKMP:(2002):deleting node 140515692 error FALSE reason "Informational (in) state 1"

Reply to
Jamie Watson

you alluded to internet traffic passing normally when the tunnel was down, if so, then this is a moot point... but nevertheless...

try debug arp & look for filtered cable segments during the dead period. compare the arp table when it's working and when it is not. also check the routing table, can you reach the tunnel destination? debug ip routing may help here.

Reply to
sfp

Cabling-Design.com Forums website is not affiliated with any of the manufacturers or service providers discussed here. All logos and trade names are the property of their respective owners.