[5.800] IPSEC VPN Broken?

(See above for screenshot attached).

Running 5.800  5.200 IPSEC connection.

Setup fine, was running great.  Tried to use it one day and found the link was down.

It's setup as a standard VPN using AES PFS.

I just killed the definition for it and recreated from scratch, now the VPN status display isn't showing at all.  Very weird behavior!

000  
000 "S_Work_0": X.X.X.0/24===203.59.133.153[@sputcorp.gotdns.com,S?C]...203.153.227.210[S?C]===X.X.X.0/24; unrouted; eroute owner: #0
000 "S_Work_0":     srcip=unset; dstip=unset
000 "S_Work_0":   CAs: 'C=au, ST=WA, L=Perth, O=Home, OU=Home, CN=Bulwer Street, E=sss@micromine.com.au'...'C=au, ST=Western Australia, L=Perth, O=IT, OU=Network Manager, CN=Perth_CA, E=sss@micromine.com.au'
000 "S_Work_0":   ike_life: 7800s; ipsec_life: 3600s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0
000 "S_Work_0":   policy: RSASIG+ENCRYPT+COMPRESS+TUNNEL+PFS+UP; prio: 24,24; interface: ppp0; 
000 "S_Work_0":   dpd: action:clear; delay:30; timeout:120; 
000 "S_Work_0":   newest ISAKMP SA: #0; newest IPsec SA: #0; 
000 "S_Work_0":   IKE algorithms wanted: 5_000-1-5, flags=-strict
000 "S_Work_0":   IKE algorithms found:  5_192-1_128-5, 
000 "S_Work_0":   ESP algorithms wanted: 12_128-1, ; pfsgroup=5; flags=-strict
000 "S_Work_0":   ESP algorithms loaded: 12_128-1, ; pfsgroup=5; flags=-strict
000  
000 #1: "S_Work_0":500 STATE_MAIN_I1 (sent MI1, expecting MR1); EVENT_RETRANSMIT in 3s; nodpd
000 #1: pending Phase 2 for "S_Work_0" replacing #0
000 #2: "S_Work_0":500 STATE_MAIN_R1 (sent MR1, expecting MI2); EVENT_RETRANSMIT in 26s; nodpd
000 #3: "S_Work_0":500 STATE_MAIN_R1 (sent MR1, expecting MI2); EVENT_RETRANSMIT in 6s; nodpd
000  

(X's commenting out subnets).

Any clue?
Parents
  • Hi Simon,

    that is probably a bug in connection tracking which is already fixed in beta 5.816.

    Is there a message in ipsec.log complaining "permission denied"?

    Greetings

    Daniel
  • You mean like this?

    2005:05:24-08:52:33 (none) pluto[26684]: "S_Work_0" #2363: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
    2005:05:24-08:52:33 (none) pluto[26684]: ERROR: "S_Work_0" #2363: sendto on ppp0 to 203.153.227.210:500 failed in STATE_MAIN_R0. Errno 1: Operation not permitted
    2005:05:24-08:52:43 (none) pluto[26684]: ERROR: "S_Work_0" #2363: sendto on ppp0 to 203.153.227.210:500 failed in EVENT_RETRANSMIT. Errno 1: Operation not permitted

    I'll install new beta tonight.
  • "Operation not permitted"
    This happens at the moment ipsec is loaded, but packetfilters are not in place yet. A short race condidtion. ipsec will reconnect immediatelly and then packetfilter should be in place.

    Xeno
  • Cept it isn't....  I'll throw new beta on later.

    2005:05:24-15:11:08 (none) pluto[15883]: | 
    2005:05:24-15:11:08 (none) pluto[15883]: | *time to handle event
    2005:05:24-15:11:08 (none) pluto[15883]: | handling event EVENT_RETRANSMIT
    2005:05:24-15:11:08 (none) pluto[15883]: | event after this is EVENT_RETRANSMIT in 6 seconds
    2005:05:24-15:11:08 (none) pluto[15883]: | processing connection S_Work_0
    2005:05:24-15:11:08 (none) pluto[15883]: | handling event EVENT_RETRANSMIT for 203.153.227.210 "S_Work_0" #1
    2005:05:24-15:11:08 (none) pluto[15883]: | sending 228 bytes for EVENT_RETRANSMIT through ppp0:500 to 203.153.227.210:500:
    2005:05:24-15:11:08 (none) pluto[15883]: ERROR: "S_Work_0" #1: sendto on ppp0 to 203.153.227.210:500 failed in EVENT_RETRANSMIT. Errno 1: Operation not permitted
    2005:05:24-15:11:08 (none) pluto[15883]: | inserting event EVENT_RETRANSMIT, timeout in 40 seconds for #1
    2005:05:24-15:11:08 (none) pluto[15883]: | next event EVENT_RETRANSMIT in 6 seconds for #4
    2005:05:24-15:11:14 (none) pluto[15883]: | 
    2005:05:24-15:11:14 (none) pluto[15883]: | *time to handle event
    2005:05:24-15:11:14 (none) pluto[15883]: | handling event EVENT_RETRANSMIT
    2005:05:24-15:11:14 (none) pluto[15883]: | event after this is EVENT_SHUNT_SCAN in 3 seconds
    2005:05:24-15:11:14 (none) pluto[15883]: | processing connection S_Work_0
    2005:05:24-15:11:14 (none) pluto[15883]: | handling event EVENT_RETRANSMIT for 203.153.227.210 "S_Work_0" #4
    2005:05:24-15:11:14 (none) pluto[15883]: | sending 136 bytes for EVENT_RETRANSMIT through ppp0:500 to 203.153.227.210:500:
    2005:05:24-15:11:14 (none) pluto[15883]: ERROR: "S_Work_0" #4: sendto on ppp0 to 203.153.227.210:500 failed in EVENT_RETRANSMIT. Errno 1: Operation not permitted
    2005:05:24-15:11:14 (none) pluto[15883]: | inserting event EVENT_RETRANSMIT, timeout in 20 seconds for #4
    2005:05:24-15:11:14 (none) pluto[15883]: | next event EVENT_SHUNT_SCAN in 3 seconds
    2005:05:24-15:11:17 (none) pluto[15883]: | 
    2005:05:24-15:11:17 (none) pluto[15883]: | *time to handle event
    2005:05:24-15:11:17 (none) pluto[15883]: | handling event EVENT_SHUNT_SCAN
    2005:05:24-15:11:17 (none) pluto[15883]: | event after this is EVENT_PENDING_PHASE2 in 0 seconds
    2005:05:24-15:11:17 (none) pluto[15883]: | inserting event EVENT_SHUNT_SCAN, timeout in 120 seconds
    2005:05:24-15:11:17 (none) pluto[15883]: | scanning for shunt eroutes
    2005:05:24-15:11:17 (none) pluto[15883]: | next event EVENT_PENDING_PHASE2 in 0 seconds
    2005:05:24-15:11:17 (none) pluto[15883]: | 
    2005:05:24-15:11:17 (none) pluto[15883]: | *time to handle event
    2005:05:24-15:11:17 (none) pluto[15883]: | handling event EVENT_PENDING_PHASE2
    2005:05:24-15:11:17 (none) pluto[15883]: | event after this is EVENT_RETRANSMIT in 17 seconds
    2005:05:24-15:11:17 (none) pluto[15883]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
    2005:05:24-15:11:17 (none) pluto[15883]: | pending review: connection "S_Work_0" checked
    2005:05:24-15:11:17 (none) pluto[15883]: | next event EVENT_RETRANSMIT in 17 seconds for #4



  • EVENT_RETRANSMIT through ppp0:500 to 203.153.227.210:500:
    2005:05:24-15:11:14 (none) pluto[15883]: ERROR: "S_Work_0" #4: sendto on ppp0 to 203.153.227.210:500 failed in EVENT_RETRANSMIT. Errno 1: Operation not permitted



    I have an identical error with the same problem with two ASG v 6.302


    2006:08:30-15:12:18 (none) pluto[6687]: | emitting length of ISAKMP Vendor ID Payload: 20
    2006:08:30-15:12:18 (none) pluto[6687]: | emitting length of ISAKMP Message: 196
    2006:08:30-15:12:18 (none) pluto[6687]: | sending 196 bytes for main_outI1 through eth1:500 to xx.xx.xxx.xxx:yyy:
    2006:08:30-15:12:18 (none) pluto[6687]: ERROR: "S_Salerno-Salerno2_0" #1: sendto on eth1 to 8x.xx.xxx.xxx:yyy failed in main_outI1. Errno 1: Operation not permitted
    2006:08:30-15:12:18 (none) pluto[6687]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
    2006:08:30-15:12:18 (none) pluto[6687]: | next event EVENT_RETRANSMIT in 10 seconds for #1
    2006:08:30-15:12:28 (none) pluto[6687]: |
    2006:08:30-15:12:28 (none) pluto[6687]: | *time to handle event
    2006:08:30-15:12:28 (none) pluto[6687]: | handling event EVENT_RETRANSMIT
Reply Children