This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

Strange VPN problem => %trap:0

Strange VPN problem.

I have 2 tunnels between 2 ASL 5 boxes (tunnel A and tunnel B for 2 different subnets).
Everything works perfectly and the VPN is alive.
From time to time (+ - 36 hours) one of the tunnels is "trapped"
And it is always happens in tunnel B and never in tunnel A.

In order to fix that I have to restart the B tunnel from the web interface in both firewalls.

• Both tunnel use the same key and and IPSEC protocol.
• The lifetime is the same on both ASL boxes.
• One of the firewalls is behind NAT


Any solution?


This thread was automatically locked due to age.
Parents
  • no answer for this problem???????
    it is killing me
  • Hi,

    can you post some logs, from the concerning time. And what Version are you using.

    Chris
  • Hi Chris,

    Property here the same problem.

    (lifetime 3600sec.)

    2005:09:13-00:35:52 (none) pluto[2300]: "S_Serrig-DMZ-DacsysN_0" #1215: responding to Quick Mode {msgid:36d940b3}
    2005:09:13-00:35:52 (none) pluto[2300]: "S_Serrig-DMZ-DacsysN_0" #1215: transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
    2005:09:13-00:35:52 (none) pluto[2300]: "S_Serrig-DMZ-DacsysN_0" #1215: Dead Peer Detection (RFC 3706): enabled
    2005:09:13-00:35:52 (none) pluto[2300]: "S_Serrig-DMZ-DacsysN_0" #1215: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
    2005:09:13-00:35:52 (none) pluto[2300]: "S_Serrig-DMZ-DacsysN_0" #1215: IPsec SA established {ESP=>0x3fdbd1e3  192.168.100.0/24   => %trap

    Possibly an idea?

    Stefan
  • Here still more information in the Debug mode.

    2005:09:13-10:13:08 (none) pluto[3418]: | *received whack message
    2005:09:13-10:13:08 (none) pluto[3418]: | Added new connection S_Serrig-DMZ-Dacsys_0 with policy RSASIG+ENCRYPT+TUNNEL+PFS
    2005:09:13-10:13:08 (none) pluto[3418]: | from whack: got --esp=aes128-md5;modp1536
    2005:09:13-10:13:08 (none) pluto[3418]: | esp string values: 12_128-1, ; pfsgroup=5; flags=-strict
    2005:09:13-10:13:08 (none) pluto[3418]: | from whack: got --ike=aes256-md5-modp1536
    2005:09:13-10:13:08 (none) pluto[3418]: | ike string values: 7_256-1-5, flags=-strict
    2005:09:13-10:13:08 (none) pluto[3418]: | counting wild cards for 194.154.219.194 is 0
    2005:09:13-10:13:08 (none) pluto[3418]: | counting wild cards for 217.6.34.2 is 0
    2005:09:13-10:13:08 (none) pluto[3418]: | alg_info_addref() alg_info->ref_cnt=1
    2005:09:13-10:13:08 (none) pluto[3418]: | alg_info_addref() alg_info->ref_cnt=1
    2005:09:13-10:13:08 (none) pluto[3418]: | alg_info_addref() alg_info->ref_cnt=2
    2005:09:13-10:13:08 (none) pluto[3418]: | alg_info_addref() alg_info->ref_cnt=2
    2005:09:13-10:13:08 (none) pluto[3418]: added connection description "S_Serrig-DMZ-Dacsys_0"
    2005:09:13-10:13:08 (none) pluto[3418]: | 192.168.0.0/24===194.154.219.xxx...217.6.34.xxx===192.168.100.0/24
    2005:09:13-10:13:08 (none) pluto[3418]: | ike_life: 7800s; ipsec_life: 3600s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: RSASIG+ENCRYPT+TUNNEL+PFS
    2005:09:13-10:13:08 (none) pluto[3418]: | next event EVENT_RETRANSMIT in 10 seconds for #1
    2005:09:13-10:13:08 (none) pluto[3418]: |  
    2005:09:13-10:13:08 (none) pluto[3418]: | *received whack message
    2005:09:13-10:13:08 (none) ipsec_starter[9839]: Setting --esp=aes128-md5;modp1536
    2005:09:13-10:13:08 (none) pluto[3418]: | next event EVENT_RETRANSMIT in 10 seconds for #1
    2005:09:13-10:13:08 (none) pluto[3418]: |  
    2005:09:13-10:13:08 (none) pluto[3418]: | *received whack message
    2005:09:13-10:13:08 (none) pluto[3418]: | next event EVENT_RETRANSMIT in 10 seconds for #1
    2005:09:13-10:13:08 (none) pluto[3418]: |  
    2005:09:13-10:13:08 (none) pluto[3418]: | *received whack message
    2005:09:13-10:13:08 (none) pluto[3418]: | processing connection S_Serrig-DMZ-Dacsys_0
    2005:09:13-10:13:08 (none) pluto[3418]: | Queuing pending Quick Mode with 217.6.34.xxx "S_Serrig-DMZ-Dacsys_0"
    2005:09:13-10:13:08 (none) pluto[3418]: | next event EVENT_RETRANSMIT in 10 seconds for #1
    2005:09:13-10:13:08 (none) pluto[3418]: |

    and

    2005:09:13-10:13:10 (none) pluto[3418]: "S_Serrig-DMZ-Dacsys_0" #5: can not start crypto helper: failed to find any available worker

    2005:09:13-10:13:10 (none) pluto[3418]: | *time to handle event
    2005:09:13-10:13:10 (none) pluto[3418]: | handling event EVENT_SO_DISCARD
    2005:09:13-10:13:10 (none) pluto[3418]: | event after this is EVENT_SO_DISCARD in 0 seconds
    2005:09:13-10:13:10 (none) pluto[3418]: | processing connection S_Serrig-DMZ-Dacsys_0
    2005:09:13-10:13:10 (none) pluto[3418]: | deleting state #5
    2005:09:13-10:13:10 (none) pluto[3418]: | processing connection S_Serrig-DMZ-Dacsys_0
    2005:09:13-10:13:10 (none) pluto[3418]: | ICOOKIE:  3b 0f 19 b1  8c b3 f8 3b
    2005:09:13-10:13:10 (none) pluto[3418]: | RCOOKIE:  12 dc 18 dd  e5 3b 4b 89
    2005:09:13-10:13:10 (none) pluto[3418]: | peer:  d9 06 22 02
    2005:09:13-10:13:10 (none) pluto[3418]: | state hash entry 0
    2005:09:13-10:13:10 (none) pluto[3418]: | next event EVENT_SO_DISCARD in 0 seconds for #4 

    2005:09:13-10:17:05 (none) pluto[3418]: | pending review: connection "S_Serrig-DMZ-Dacsys_0" checked 

    Stefan
  • Hm,

    2005:09:13-05:44:04 (none) pluto[2300]: pending Quick Mode with 194.154.219.XXX "S_Serrig-DMZ-DacsysN_0" took too long -- replacing phase 1

    looks like the remote endpoint is not responding anymore. Do you have some logs from the remote endpoint. 

    Chris
  • Chris,

    we regard this time frame somewhat more exactly.

    ASL 1:

    2005:09:13-05:44:04 (none) pluto[2300]: pending Quick Mode with 194.154.219.xxx "S_Serrig-Intern-DacsysN_0" took too long -- replacing phase 1
    2005:09:13-05:44:04 (none) pluto[2300]: pending Quick Mode with 194.154.219.xxx "S_VPN__Clients__Serrig__Dacsys_0" took too long -- replacing phase 1
    2005:09:13-05:44:04 (none) pluto[2300]: pending Quick Mode with 194.154.219.xxx "S_DasysISDN-Serrig-DMZ__N_0" took too long -- replacing phase 1
    2005:09:13-05:44:04 (none) pluto[2300]: pending Quick Mode with 194.154.219.xxx "S_DasysISDN-Serrig-InternN_0" took too long -- replacing phase 1
    2005:09:13-05:44:04 (none) pluto[2300]: pending Quick Mode with 194.154.219.xxx "S_Serrig-ISDN-DasysN_0" took too long -- replacing phase 1
    2005:09:13-05:44:04 (none) pluto[2300]: pending Quick Mode with 194.154.219.xxx "S_Serrig-DMZ-DacsysN_0" took too long -- replacing phase 1

    ASL2

    2005:09:13-05:43:42 (none) pluto[9878]: pending Quick Mode with 217.6.34.xxx "S_DasysISDN-Serrig-Intern_0" took too long -- replacing phase 1
    2005:09:13-05:43:42 (none) pluto[9878]: pending Quick Mode with 217.6.34.xxx "S_Serrig-ISDN-Dasys_0" took too long -- replacing phase 1
    2005:09:13-05:43:42 (none) pluto[9878]: pending Quick Mode with 217.6.34.xxx "S_DasysISDN-Serrig-DMZ_0" took too long -- replacing phase 1
    2005:09:13-05:43:42 (none) pluto[9878]: pending Quick Mode with 217.6.34.xxx "S_Serrig-DMZ-Dacsys_0" took too long -- replacing phase 1
    2005:09:13-05:43:42 (none) pluto[9878]: pending Quick Mode with 217.6.34.xxx "S_VPN__Clients__Serrig__Dacsys_0" took too long -- replacing phase 1
    2005:09:13-05:43:42 (none) pluto[9878]: pending Quick Mode with 217.6.34.xxx "S_Serrig-Intern-Dacsys_0" took too long -- replacing phase 1

    There are 6 VPN connections between ASL1 and ASL2.
    As one sees had all 6 connections problems. 4 VPN connections started automatically again.
    2 VPN connections were constant on "trap".

    Why here don't the other two start automatically?
    Why don't "Dead Peer Detection" become actively?
    This behavior I already several times observed.

    Here helps only if I the appropriate VPN connection start again.

    Stefan
  • Looks like a bug to me. 

    You could try using differen timeouts, with every 2 or 3 connections. So they have to do a rekeying at different times, not all at the same time.

    I will write you a PM in german.

    Chris
  • Hi Nimmdirkeks,

    I have the same problem %trap:0 with my ASL5 (5.203 behind NAT) and ASG110 (5.206).
    The VPN was good until the last friday...today, I restarted the tunnels.
    Here the logs that I saw on ASL5:

    000 "S_AAA_0": 172.16.75.0/24===192.168.100.20:4500[@bbb-fw]...1.2.3.4:25942[@ccc-fw]===172.16.66.0/24
    000 "S_AAA_0":   CAs: '%any'...'%any'
    000 "S_AAA_0":   ike_life: 7800s; ipsec_life: 3600s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0
    000 "S_AAA_0":   policy: RSASIG+ENCRYPT+TUNNEL+PFS; interface: eth0; erouted
    000 "S_AAA_0":   newest ISAKMP SA: #97461; newest IPsec SA: #97463; eroute owner: #97463
    000 "S_AAA_0":   IKE algorithms wanted: 5_000-1-5, flags=-strict
    000 "S_AAA_0":   IKE algorithms found:  5_192-1_128-5, 
    000 "S_AAA_0":   IKE algorithm newest: 3DES_CBC_192-MD5-MODP1536
    000 "S_AAA_0":   ESP algorithms wanted: 12_128-1, ; pfsgroup=5; flags=-strict
    000 "S_AAA_0":   ESP algorithms loaded: 12_128-1_128, 
    000 "S_AAA_0":   ESP algorithm newest: AES_128-HMAC_MD5; pfsgroup=MODP1536

    Look at this strange port: 1.2.3.4:25942[@ccc-fw].
    It should be 4500 !

    Bye
Reply
  • Hi Nimmdirkeks,

    I have the same problem %trap:0 with my ASL5 (5.203 behind NAT) and ASG110 (5.206).
    The VPN was good until the last friday...today, I restarted the tunnels.
    Here the logs that I saw on ASL5:

    000 "S_AAA_0": 172.16.75.0/24===192.168.100.20:4500[@bbb-fw]...1.2.3.4:25942[@ccc-fw]===172.16.66.0/24
    000 "S_AAA_0":   CAs: '%any'...'%any'
    000 "S_AAA_0":   ike_life: 7800s; ipsec_life: 3600s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0
    000 "S_AAA_0":   policy: RSASIG+ENCRYPT+TUNNEL+PFS; interface: eth0; erouted
    000 "S_AAA_0":   newest ISAKMP SA: #97461; newest IPsec SA: #97463; eroute owner: #97463
    000 "S_AAA_0":   IKE algorithms wanted: 5_000-1-5, flags=-strict
    000 "S_AAA_0":   IKE algorithms found:  5_192-1_128-5, 
    000 "S_AAA_0":   IKE algorithm newest: 3DES_CBC_192-MD5-MODP1536
    000 "S_AAA_0":   ESP algorithms wanted: 12_128-1, ; pfsgroup=5; flags=-strict
    000 "S_AAA_0":   ESP algorithms loaded: 12_128-1_128, 
    000 "S_AAA_0":   ESP algorithm newest: AES_128-HMAC_MD5; pfsgroup=MODP1536

    Look at this strange port: 1.2.3.4:25942[@ccc-fw].
    It should be 4500 !

    Bye
Children
No Data