Thread Info
  • State Not Answered
  • Locked Locked
  • Replies 18 replies
  • Subscribers 1 subscriber
  • Views 17455 views
  • Users 0 members are here
Options
Suggested
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

No S2S tunnel - whack message

LoD
Hi @all!

I encountered a problem within the following setup:
One site has a static IP and ASG 220 (11.22.33.44) with actual firmware. The other side has the home version with dynamic IP (LoD-Home, 79.204.153.3) and also the actual firmware. Since version 8.203 the S2S connection isn't established automatically.

Settings on advanced tab:

local X509 cert; DPD off; NAT off; CRL auto fetching off; strict policy off; probing of preshared keys off.

I used the command center to set it up, using AES-256 (ACC) encryption.The dynamic ip is re-assigned every day at 0700am. But the connection won't establish. Also deleted and re-created the S2S connection. Then it's connecting at first try, but the next day it doesn't.

I'm quite sure this was not a problem with V 8.202. Anyone out there who can help?

Here are some log snips: 


2011:12:29-07:50:42 lod pluto[30059]: loading secrets from "/etc/ipsec.secrets"

2011:12:29-07:50:42 lod pluto[30059]: loaded PSK secret for 79.204.153.3 %any

2011:12:29-07:50:42 lod pluto[30059]: loading ca certificates from '/etc/ipsec.d/cacerts'

2011:12:29-07:50:42 lod pluto[30059]: loaded ca certificate from '/etc/ipsec.d/cacerts/VPN Signing CA.pem'

2011:12:29-07:50:42 lod pluto[30059]: | authcert is already present and identical

2011:12:29-07:50:42 lod pluto[30059]: loading aa certificates from '/etc/ipsec.d/aacerts'

2011:12:29-07:50:42 lod pluto[30059]: loading ocsp certificates from '/etc/ipsec.d/ocspcerts'

2011:12:29-07:50:42 lod pluto[30059]: loading attribute certificates from '/etc/ipsec.d/acerts'

2011:12:29-07:50:42 lod pluto[30059]: Changing to directory '/etc/ipsec.d/crls'

2011:12:29-07:50:42 lod pluto[30059]: | next event EVENT_RETRANSMIT in 10 seconds for #1

2011:12:29-07:50:42 lod pluto[30059]: |

2011:12:29-07:50:42 lod pluto[30059]: | *received 68 bytes from 11.22.33.44:500 on ppp0

2011:12:29-07:50:42 lod pluto[30059]: | ICOOKIE: 61 78 1b 8c 9e 4b e3 cc

2011:12:29-07:50:42 lod pluto[30059]: | RCOOKIE: 61 b2 91 8b f6 1a 98 bd

2011:12:29-07:50:42 lod pluto[30059]: | peer: 50 9c dd d2

2011:12:29-07:50:42 lod pluto[30059]: | state hash entry 9

2011:12:29-07:50:42 lod pluto[30059]: | state object not found

2011:12:29-07:50:42 lod pluto[30059]: packet from 11.22.33.44:500: ignoring informational payload, type NO_PROPOSAL_CHOSEN

2011:12:29-07:50:42 lod pluto[30059]: | next event EVENT_RETRANSMIT in 10 seconds for #1

2011:12:29-07:50:52 lod pluto[30059]: |

...

2011:12:29-07:51:25 lod pluto[30059]: | *received whack message

...

2011:12:29-07:52:08 lod pluto[30059]: | *received 56 bytes from 11.22.33.44:500 on ppp0

2011:12:29-07:52:08 lod pluto[30059]: | ICOOKIE: 61 78 1b 8c 9e 4b e3 cc

2011:12:29-07:52:08 lod pluto[30059]: | RCOOKIE: 61 b2 91 8b f6 1a 98 bd

2011:12:29-07:52:08 lod pluto[30059]: | peer: 50 9c dd d2

2011:12:29-07:52:08 lod pluto[30059]: | state hash entry 9

2011:12:29-07:52:08 lod pluto[30059]: | state object not found

2011:12:29-07:52:08 lod pluto[30059]: packet from 11.22.33.44:500: ignoring Delete SA payload: not encrypted

2011:12:29-07:52:08 lod pluto[30059]: | next event EVENT_RETRANSMIT in 24 seconds for #1

2011:12:29-07:52:10 lod pluto[30059]: |

2011:12:29-07:52:10 lod pluto[30059]: | *received whack message

2011:12:29-07:52:10 lod pluto[30059]: | next event EVENT_RETRANSMIT in 22 seconds for #1

2011:12:29-07:52:32 lod pluto[30059]: |

2011:12:29-07:52:32 lod pluto[30059]: | *time to handle event

2011:12:29-07:52:32 lod pluto[30059]: | event after this is EVENT_REINIT_SECRET in 3467 seconds

2011:12:29-07:52:32 lod pluto[30059]: | handling event EVENT_RETRANSMIT for 11.22.33.44 "S_LoD-Home" #1

2011:12:29-07:52:32 lod pluto[30059]: | inserting event EVENT_RETRANSMIT, timeout in 40 seconds for #1

2011:12:29-07:52:32 lod pluto[30059]: | next event EVENT_RETRANSMIT in 40 seconds for #1

2011:12:29-07:52:32 lod pluto[30059]: |

2011:12:29-07:52:32 lod pluto[30059]: | *received 68 bytes from 11.22.33.44:500 on ppp0

2011:12:29-07:52:32 lod pluto[30059]: | ICOOKIE: 61 78 1b 8c 9e 4b e3 cc

2011:12:29-07:52:32 lod pluto[30059]: | RCOOKIE: a2 af c4 25 99 fe 2a 3f

2011:12:29-07:52:32 lod pluto[30059]: | peer: 50 9c dd d2

2011:12:29-07:52:32 lod pluto[30059]: | state hash entry 5

2011:12:29-07:52:32 lod pluto[30059]: | state object not found

2011:12:29-07:52:32 lod pluto[30059]: packet from 11.22.33.44:500: ignoring informational payload, type NO_PROPOSAL_CHOSEN

2011:12:29-07:52:32 lod pluto[30059]: | next event EVENT_RETRANSMIT in 40 seconds for #1

...

2011:12:29-07:52:57 lod pluto[30059]: | *received whack message

2011:12:29-07:52:57 lod pluto[30059]: "S_LoD-Home": deleting connection

2011:12:29-07:52:57 lod pluto[30059]: "S_LoD-Home" #1: deleting state (STATE_MAIN_I1)

2011:12:29-07:52:57 lod pluto[30059]: | ICOOKIE: 61 78 1b 8c 9e 4b e3 cc

2011:12:29-07:52:57 lod pluto[30059]: | RCOOKIE: 00 00 00 00 00 00 00 00

2011:12:29-07:52:57 lod pluto[30059]: | peer: 50 9c dd d2

2011:12:29-07:52:57 lod pluto[30059]: | state hash entry 5

...

2011:12:29-07:52:57 lod pluto[30059]: | *received whack message

2011:12:29-07:52:57 lod pluto[30059]: listening for IKE messages

2011:12:29-07:52:57 lod pluto[30059]: | found lo with address 127.0.0.1

2011:12:29-07:52:57 lod pluto[30059]: | found eth0 with address 192.168.1.254

2011:12:29-07:52:57 lod pluto[30059]: | found wlan0 with address 172.16.28.1

2011:12:29-07:52:57 lod pluto[30059]: | found ppp0 with address 79.204.153.3

2011:12:29-07:52:57 lod pluto[30059]: | found lo with address 0000:0000:0000:0000:0000:0000:0000:0001

2011:12:29-07:52:57 lod pluto[30059]: forgetting secrets

2011:12:29-07:52:57 lod pluto[30059]: loading secrets from "/etc/ipsec.secrets"

2011:12:29-07:52:57 lod pluto[30059]: loaded PSK secret for 79.204.153.3 %any

2011:12:29-07:52:57 lod pluto[30059]: | next event EVENT_REINIT_SECRET in 3442 seconds

2011:12:29-07:52:57 lod pluto[30059]: |

2011:12:29-07:52:57 lod pluto[30059]: | *received whack message

...

2011:12:29-08:01:07 lod pluto[30059]: |

2011:12:29-08:01:07 lod pluto[30059]: | *received whack message

2011:12:29-08:01:07 lod pluto[30059]: | from whack: got --esp=aes256-md5

2011:12:29-08:01:07 lod pluto[30059]: | esp alg added: AES_CBC_256/HMAC_MD5, cnt=1

2011:12:29-08:01:07 lod pluto[30059]: | esp proposal: AES_CBC_256/HMAC_MD5,

2011:12:29-08:01:07 lod pluto[30059]: | from whack: got --ike=aes256-md5-modp1536

2011:12:29-08:01:07 lod pluto[30059]: | ikg alg added: AES_CBC_256/HMAC_MD5/MODP_1536, cnt=1

2011:12:29-08:01:07 lod pluto[30059]: | ike proposal: AES_CBC_256/HMAC_MD5/MODP_1536,

2011:12:29-08:01:07 lod pluto[30059]: added connection description "S_LoD-Home"

2011:12:29-08:01:07 lod pluto[30059]: | 192.168.1.0/24===79.204.153.3[79.204.153.3]...11.22.33.44[11.22.33.44]===192.168.178.0/24

2011:12:29-08:01:07 lod pluto[30059]: | ike_life: 7800s; ipsec_life: 3600s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: PUBKEY+ENCRYPT+TUNNEL

2011:12:29-08:01:07 lod pluto[30059]: | next event EVENT_REINIT_SECRET in 2952 seconds

...

2011:12:29-08:01:07 lod pluto[30059]: |

2011:12:29-08:01:07 lod pluto[30059]: | *received whack message

2011:12:29-08:01:07 lod pluto[30059]: | creating state object #2 at 0x945a6f8

2011:12:29-08:01:07 lod pluto[30059]: | ICOOKIE: 32 1d 4b 07 95 c9 58 40

2011:12:29-08:01:07 lod pluto[30059]: | RCOOKIE: 00 00 00 00 00 00 00 00

2011:12:29-08:01:07 lod pluto[30059]: | peer: 50 9c dd d2

2011:12:29-08:01:07 lod pluto[30059]: | state hash entry 2

2011:12:29-08:01:07 lod pluto[30059]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2

2011:12:29-08:01:07 lod pluto[30059]: | Queuing pending Quick Mode with 11.22.33.44 "S_LoD-Home"

2011:12:29-08:01:07 lod pluto[30059]: "S_LoD-Home" #2: initiating Main Mode

2011:12:29-08:01:07 lod pluto[30059]: | ike proposal: AES_CBC_256/HMAC_MD5/MODP_1536,

2011:12:29-08:01:07 lod pluto[30059]: "S_LoD-Home" #2: ike alg: unable to retrieve my private key

2011:12:29-08:01:07 lod pluto[30059]: "S_LoD-Home" #2: empty ISAKMP SA proposal to send (no algorithms for ike selection?)

2011:12:29-08:01:07 lod pluto[30059]: | next event EVENT_SO_DISCARD in 0 seconds for #2

2011:12:29-08:01:07 lod pluto[30059]: |

2011:12:29-08:01:07 lod pluto[30059]: | *time to handle event

2011:12:29-08:01:07 lod pluto[30059]: | event after this is EVENT_REINIT_SECRET in 2952 seconds

2011:12:29-08:01:07 lod pluto[30059]: | ICOOKIE: 32 1d 4b 07 95 c9 58 40

2011:12:29-08:01:07 lod pluto[30059]: | RCOOKIE: 00 00 00 00 00 00 00 00

2011:12:29-08:01:07 lod pluto[30059]: | peer: 50 9c dd d2

2011:12:29-08:01:07 lod pluto[30059]: | state hash entry 2

...


The only way to re-enable the connection is to disable it in the command center, wait about 10/15 minutes and enable it again. Both sides are not using NAT and are set up as initial connections as they are both the local network endpoint. No further router. Is that correct?

Greetinx
LoD


This thread was automatically locked due to age.
  • 0 in reply to LoD
    After the reconnect, when the tunnel is broken, run these commands in a shell and post the output:


    ip addr
    ipsec status


    I suspect the IP address of the external interface to differ from the one configured for IPsec.
  • 0 in reply to d12fk
    One and a half hour ago the connection should have been re-established but it wasn't.

    ip addr gives me: 

    29: ppp0:  mtu 1492 qdisc pfifo_fast state UNKNOWN qlen 3

        link/ppp 

        inet 79.204.184.76 peer 217.0.118.146/32 scope global ppp0


    where 79.204.184.76 is the public vpn endpoint which is also shown on workside:

    SA:  192.168.178.0/24=11.22.33.44  79.204.184.76=192.168.1.0/24

    The ipsec status just returns "You must be root to run this command." -> and as root "bash: ipsec: command not found" (even on the ASG220 the ipsec command isn't found).

    Is there anything else I can provide to solve the problem?

    Regards,
    LoD
  • 0 in reply to LoD
    Next time try "/usr/local/bin/ipsec status" it's probably just missing in your $PATH.
  • 0 in reply to d12fk
    Oh, I should have taken look in /usr/local.

    Here's the result of the software asg (HOME): 

    000 "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_0_0": 192.168.1.0/24===79.204.186.94[dyn.dns.org]...11.22.33.210[mail.tld.de]===192.168.178.0/24; unrouted; eroute owner: #0

    000 "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_0_0":   newest ISAKMP SA: #0; newest IPsec SA: #0; 

    000 "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_0_1": 192.168.1.0/24===79.204.186.94[dyn.dns.org]...11.22.33.44[mail.tld.de]===192.168.2.0/24; unrouted; eroute owner: #0

    000 "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_0_1":   newest ISAKMP SA: #0; newest IPsec SA: #0; 

    000 "S_REF_IpsL2t1_0": 79.204.186.94[79.204.186.94]:17/1701...%any[%any]:17/%any==={0.0.0.0/0}; unrouted; eroute owner: #0

    000 "S_REF_IpsL2t1_0":   newest ISAKMP SA: #0; newest IPsec SA: #0; 

    000 "S_REF_IpsL2t1_1": 79.204.186.94[79.204.186.94]:17/0...%any[%any]:17/%any==={0.0.0.0/0}; unrouted; eroute owner: #0

    000 "S_REF_IpsL2t1_1":   newest ISAKMP SA: #0; newest IPsec SA: #0; 

    000 

    000 #6: "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_0_0" STATE_MAIN_I1 (sent MI1, expecting MR1); EVENT_RETRANSMIT in 36s

    000 #6: pending Phase 2 for "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_0_1" replacing #0

    000 #6: pending Phase 2 for "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_0_0" replacing #0

    000 


    and from ASG 220 (WORK): 

    000 "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_1_0": 192.168.178.0/24===11.22.33.44[mail.tld.de]...79.204.186.94[dyn.dns.org]===192.168.1.0/24; unrouted; eroute owner: #0

    000 "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_1_0":   newest ISAKMP SA: #0; newest IPsec SA: #0; 

    000 "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_1_1": 192.168.2.0/24===11.22.33.44[mail.tld.de]...79.204.186.94[dyn.dns.org]===192.168.1.0/24; unrouted; eroute owner: #0

    000 "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_1_1":   newest ISAKMP SA: #0; newest IPsec SA: #0; 

    000 "S_REF_IpsL2t1_0": 217.***.YYY.ZZZ[217.***.YYY.ZZZ]:17/1701...%any[%any]:17/%any==={0.0.0.0/0}; unrouted; eroute owner: #0

    000 "S_REF_IpsL2t1_0":   newest ISAKMP SA: #0; newest IPsec SA: #0; 

    000 "S_REF_IpsL2t1_1": 217.***.YYY.ZZZ[217.***.YYY.ZZZ]:17/0...%any[%any]:17/%any==={0.0.0.0/0}; unrouted; eroute owner: #0

    000 "S_REF_IpsL2t1_1":   newest ISAKMP SA: #0; newest IPsec SA: #0; 

    000 

    000 #35: "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_1_0" STATE_MAIN_I1 (sent MI1, expecting MR1); EVENT_RETRANSMIT in 38s

    000 #35: pending Phase 2 for "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_1_1" replacing #0

    000 #35: pending Phase 2 for "S_REF_ACC_LOC_e27994c28b2341ce822f1f87c9e264cf64cf_1_0" replacing #0

    000 


    I guess you're getting closer. 217.***.YYY.ZZZ is the second line on ASG 220 which should be used for web surfing only. So there's some bad public ip mapping?! Where can I check that? Is that a missing multipath rule for IPSec ?


    regards,
    LoD
  • 0
    Here are the tricks to making IPsec work with Uplink Balancing:

    In the ASG220: Use "Uplink Interfaces" in the 'IPsec Connection' instead of "External (CC)" in 'Local interface'.  Create a Multipath rule like 'Any -> IPsec -> {your home IP} : bind to External (CC)'.

    In your home Astaro: In 'Gateway' in the 'Remote Gateway' definition, instead of using a Host definiton with the IP of "External (CC) (Address)", create an 'Availability Group' with, in order, that Host definition, and then a second one for the IP of "External (WAN) (Address)".

    Maybe someone that knows the internals can explain to us if that solves your issue.

    Cheers - Bob
     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • 0 in reply to BAlfson
    Hi Bob,

    that sounds good and logical to me. But: I deleted the GM-created connection and  created a new one with the changes you gave. Connection was established immediately.

    I then reconnected the home-asg and the connection wasn't established automatically. 

    HOME: packet from 11.22.33.44:500: initial Main Mode message received on 79.204.152.146:500 but no connection has been authorized with policy=PUBKEY 

    ASG220: 
    packet from 79.204.152.146:500: initial Main Mode message received on 217.***.YYY.ZZZ:500 but no connection has been authorized with policy=PUBKEY
    2012:01:13-09:40:48 mail ipsec_starter[7891]: no default route - cannot cope with %defaultroute!!! 
    ...
    2012:01:13-09:54:48 mail pluto[7893]: "S_S2S.Home" #175: max number of retransmissions (20) reached STATE_MAIN_I1. No response (or no acceptable response) to our first IKE message

    After half an hour I disabled the connections on both sides, waited about 5 minutes and enabled them again => now it's working again.

    Confusing, isn't it? I'll play around with the settings a bit (e.g. changing interface order and so on) and report results.

    greetinx and have a nice weekend
    LoD
  • 0 in reply to LoD
    Good morning,

    the only solution I found until now is to disable the home-side VPN-tunnel and reactivate it after about 5 minutes. Maybe that can be done by a cronjob?!

    The best would be to make it work automatically. It's not clear why it was working directly after moving from Lancom and now isn't.

    Maybe s/o has some hints. The logfiles still indicates an attempt to connect to the wrong public IP on work-side.

    greetinx
    LoD
  • 0 in reply to LoD
    Finally it's working now.

    First I reset the home ASG (I guess this step wasn't the important one, but... it's working)

    The trouble with routing:
    On ASG-side we have two internet connections: A company connect (plain ethernet) and an aDSL (PPPoE).

    When I created the PPPoE as first line it's marked as "default gateway".
    Setting up the CC requires to add a default gateway in order to connect the ASG to the TKom-Cisco-Router.

    I unmarked default gateway on the PPPoE-line and used multipath rules to make everything but VPN using the PPPoE-connection.

    Now it's working,

    Cheers,
    LOD
Unfiltered HTML