Thread Info
  • State Not Answered
  • Replies 5 replies
  • Subscribers 0 subscribers
  • Views 5142 views
  • Users 0 members are here
Options
Suggested

AICv10.23 unable to establish the connection

thegreatoracle
It's been days but I can't get the answer until now. I have tried to change all the setting but still can't really get the correct setting.

My current IPSec VPN setting  use default AES-128 PFS policy for connection and for the authentication I use local cert.

Below is the client log when I tried to connect to VPN server.

Mon Oct 11 01:40:27 2010:IpsDialChan::s_conreq
Mon Oct 11 01:40:27 2010:IPSec: Start building connection
Mon Oct 11 01:40:27 2010:System: pthru AddVpnPort port=500
Mon Oct 11 01:40:27 2010:Link: Adding LwsGateway
Mon Oct 11 01:40:27 2010:IPSec: UpdateSpd - 1
Mon Oct 11 01:40:27 2010:CreateSpdEntry:Adapter-0,Name-Exchange,Count-1 
Mon Oct 11 01:40:27 2010:Link: Adding LwsGateway
Mon Oct 11 01:40:27 2010:IPSec: SYSTEM->IPS - connect_phase1,spdindex=1
Mon Oct 11 01:40:27 2010:Link: ChanConReq( Exit Okey )
Mon Oct 11 01:40:27 2010:Ike: internal_reqphase1:Creating a new IKE SA outgoing
Mon Oct 11 01:40:27 2010:Ike: ConRef=7, IkeSaCreated - TotNumIkeSa's=1
Mon Oct 11 01:40:27 2010:Ike: ConRef=0, Setting Slow Line - 0
Mon Oct 11 01:40:27 2010:Ike: Outgoing connect request MAIN mode - gateway=172.16.179.4 : Exchange
Mon Oct 11 01:40:27 2010:Ike: ConRef=7, XMIT_MSG1_MAIN - Exchange
Mon Oct 11 01:40:27 2010:Ike: XMIT_MSG1_MAIN - Exchange
Mon Oct 11 01:40:27 2010:Ike: ConRef=7, recv_msg -> setting RealAdapterIndex = 200
Mon Oct 11 01:40:27 2010:Ike: ConRef=7, RECV_MSG2_MAIN - Exchange
Mon Oct 11 01:40:27 2010:Ike: RECV_MSG2_MAIN - Exchange
Mon Oct 11 01:40:27 2010:IpsDial: GetMyIpAdr aindex=200,ipadr = 0a00005b
Mon Oct 11 01:40:27 2010:Ike: ConRef=7, setting local ip address 10.00.00.91
Mon Oct 11 01:40:27 2010:Ike: ConRef=7, setting final tep 172.16.179.04
Mon Oct 11 01:40:27 2010:Ike: IKE phase I: Setting LifeTime to 28800 seconds
Mon Oct 11 01:40:27 2010:Ike: IkeSa negotiated with the following properties -
Mon Oct 11 01:40:27 2010:  Authentication=RSA_SIGNATURES,Encryption=AES,Hash=MD5,DHGroup=2,KeyLen=128
Mon Oct 11 01:40:27 2010:Ike: ConRef=7, IkeSa negotiated with the following properties -
Mon Oct 11 01:40:27 2010:  Authentication=RSA_SIGNATURES,Encryption=AES,Hash=MD5,DHGroup=2,KeyLen=128
Link: Adding LwsGateway
Mon Oct 11 01:40:27 2010:Mon Oct 11 01:40:27 2010:IPSec: Final Tunnel EndPoint is:172.016.179.004
Ike: ConRef=7, Exchange ->Support for NAT-T version - 9
Mon Oct 11 01:40:27 2010:Ike: Exchange ->Support for NAT-T version - 9
Mon Oct 11 01:40:27 2010:Ike: ConRef=7, XMIT_MSG3_MAIN - Exchange
Mon Oct 11 01:40:27 2010:Ike: XMIT_MSG3_MAIN - Exchange
Mon Oct 11 01:40:31 2010:Ike: ConRef=7, retry timeout - resend ->
Mon Oct 11 01:40:36 2010:Ike: ConRef=7, retry timeout - resend ->
Mon Oct 11 01:40:37 2010:Ike: ConRef=7, recv_msg -> setting RealAdapterIndex = 200
Mon Oct 11 01:40:42 2010:Ike: ConRef=7, retry timeout - resend ->
Mon Oct 11 01:40:49 2010:ERROR - 4022: IKE(phase1):Lost contact to Gateway (No Response) in state  - Exchange.
Mon Oct 11 01:40:49 2010:Ike: ConRef=7,  name=Exchange,msg=enter_state_closed - 
  
Mon Oct 11 01:40:49 2010:Ike: phase1:name(Exchange) - ERROR - retry timeout - max retries
Mon Oct 11 01:40:49 2010:Ike: ConRef=7, send_delete - Exchange
Mon Oct 11 01:40:49 2010:IPSec: IKE->IPS:IpsDelIkeSa - 0 
Mon Oct 11 01:40:49 2010:IPSec: IKE->IPS: phase I SA(00000007) is gone 
Mon Oct 11 01:40:49 2010:Mon Oct 11 01:40:49 2010:IpsDialCb::enter_closed_state(0)
Ike: ConRef=7, IkeSaDeleted - TotNumIkeSa's=0
Mon Oct 11 01:40:49 2010:RemoveSpdEntry:Adapter-0,Name-Exchange,Count-0 
Mon Oct 11 01:40:49 2010:IpsDial: linkdown(id = 1)
Mon Oct 11 01:40:49 2010:IPSec: Disconnected from Exchange on channel 1.
Mon Oct 11 01:40:49 2010[[:P]]PP(Lcp): linkdown(237fb84)
Mon Oct 11 01:40:49 2010:BaseCp::enter_closed_state(c021)
Mon Oct 11 01:40:49 2010[[:P]]PP(Lcp): linkdown exit(237fb84)
Mon Oct 11 01:40:49 2010:Link: Deleting LwsGateway
Mon Oct 11 01:40:49 2010:Ike: internal_delikesa[:D]elete phase1(IKE)SA (SpdIndex = 1)
Mon Oct 11 01:40:51 2010:SockifEx: UdpSocket::Re


And this is the log from server.

pluto[17914]: | *time to handle event
pluto[17914]: | event after this is EVENT_REINIT_SECRET in 295 seconds
pluto[17914]: | handling event EVENT_RETRANSMIT for ***.xx.***.xx "S_EXCHANGE KC TO OFFICE" #3
pluto[17914]: | sending 176 bytes for EVENT_RETRANSMIT through eth1 to ***.xx.***.xx:56689:
pluto[17914]: | 40 cf 60 96 29 13 ec 64 fd 39 7a ef 80 2d d9 d2
pluto[17914]: | 01 10 02 00 00 00 00 00 00 00 00 b0 0d 00 00 38
pluto[17914]: | 00 00 00 01 00 00 00 01 00 00 00 2c 01 01 00 01
pluto[17914]: | 00 00 00 24 01 01 00 00 80 01 00 07 80 02 00 01
pluto[17914]: | 80 03 00 03 80 04 00 02 80 0b 00 01 80 0c 70 80
pluto[17914]: | 80 0e 00 80 0d 00 00 14 88 2f e5 6d 6f d2 0d bc
pluto[17914]: | 22 51 61 3b 2e be 5b eb 0d 00 00 14 12 f5 f2 8c
pluto[17914]: | 45 71 68 a9 70 2d 9f e2 74 cc 01 00 0d 00 00 0c
pluto[17914]: | 09 00 26 89 df d6 b7 12 0d 00 00 14 af ca d7 13
pluto[17914]: | 68 a1 f1 c9 6b 86 96 fc 77 57 01 00 00 00 00 14
pluto[17914]: | 4a 13 1c 81 07 03 58 45 5c 57 28 f2 0e 95 45 2f
pluto[17914]: | inserting event EVENT_RETRANSMIT, timeout in 40 seconds for #3
pluto[17914]: | next event EVENT_RETRANSMIT in 40 seconds for #3
2010:10:11-16:56:41 proxy01 pluto[17914]: |
2010:10:11-16:56:41 proxy01 pluto[17914]: | *time to handle event
2010:10:11-16:56:41 proxy01 pluto[17914]: | event after this is EVENT_REINIT_SECRET in 255 seconds
2010:10:11-16:56:41 proxy01 pluto[17914]: | handling event EVENT_RETRANSMIT for ***.xx.***.xx "S_EXCHANGE KC TO OFFICE" #3
2010:10:11-16:56:41 proxy01 pluto[17914]: "S_EXCHANGE KC TO OFFICE"[2] ***.xx.***.xx:56689 #3: max number of retransmissions (2) reached STATE_MAIN_R1
2010:10:11-16:56:41 proxy01 pluto[17914]: | ICOOKIE: 40 cf 60 96 29 13 ec 64
2010:10:11-16:56:41 proxy01 pluto[17914]: | RCOOKIE: fd 39 7a ef 80 2d d9 d2
2010:10:11-16:56:41 proxy01 pluto[17914]: | peer: 7b 31 79 26
2010:10:11-16:56:41 proxy01 pluto[17914]: | state hash entry 17
2010:10:11-16:56:41 proxy01 pluto[17914]: "S_EXCHANGE KC TO OFFICE"[2] ***.xx.***.xx:56689: deleting connection "S_EXCHANGE KC TO OFFICE" instance with peer ***.xx.***.xx {isakmp=#0/ipsec=#0}
2010:10:11-16:56:41 proxy01 pluto[17914]: | next event EVENT_REINIT_SECRET in 255 seconds 


Another question from me. When I run the client, it will automatically add route to my VPN server. How can I change this routing rule?
Parents
  • 0
    Hi, and welcome to the User BB!

    I notice the private IP in the client log.  Is the Astaro behind a NATting router?  Are all of the ports in the Service Group "IPsec" port-forwarded to the Astaro?  Is NAT-T selected on the 'Advanced' tab?  In the client, have you filled in the private IP of the Astaro's "External (Address)" as a 'Manual IP Address' in 'IP Address Assignment'?

    When I run the client, it will automatically add route to my VPN server. How can I change this routing rule?

    If this still is a problem after fixing any of the above, please give an example of what you see now and what you want to change it to.

    Cheers - Bob
     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
Reply
  • 0
    Hi, and welcome to the User BB!

    I notice the private IP in the client log.  Is the Astaro behind a NATting router?  Are all of the ports in the Service Group "IPsec" port-forwarded to the Astaro?  Is NAT-T selected on the 'Advanced' tab?  In the client, have you filled in the private IP of the Astaro's "External (Address)" as a 'Manual IP Address' in 'IP Address Assignment'?

    When I run the client, it will automatically add route to my VPN server. How can I change this routing rule?

    If this still is a problem after fixing any of the above, please give an example of what you see now and what you want to change it to.

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

    NAT-T is selected and I just added the Manual IP address part but another error message prompted out.

    Mon Oct 11 20:04:41 2010:Ike: NOTIFY : Exchange : RECEIVED : INVALID_ID_INFORMATION : 18
    Mon Oct 11 20:04:46 2010:Ike: NOTIFY : Exchange : RECEIVED : INVALID_MESSAGE_ID : 9
    Mon Oct 11 20:04:52 2010:Ike: ConRef=156, recv_msg -> setting RealAdapterIndex = 200
    Mon Oct 11 20:04:52 2010:Ike: ConRef=156, NOTIFY : Exchange : RECEIVED : INVALID_MESSAGE_ID : 9
    Mon Oct 11 20:04:52 2010:Ike: NOTIFY : Exchange : RECEIVED : INVALID_MESSAGE_ID : 9
    Mon Oct 11 20:04:58 2010:Ike: ConRef=156, recv_msg -> setting RealAdapterIndex = 200
    Mon Oct 11 20:04:58 2010:Ike: ConRef=156, NOTIFY : Exchange : RECEIVED : INVALID_MESSAGE_ID : 9
    Mon Oct 11 20:04:58 2010:Ike: NOTIFY : Exchange : RECEIVED : INVALID_MESSAGE_ID : 9
    Mon Oct 11 20:05:00 2010:IpsDial: Request to send dpd
    Mon Oct 11 20:05:00 2010:Ike: internal_send_dpd:send_dpd -> ikeindex = 156
    Mon Oct 11 20:05:00 2010:Ike: ConRef=156, request from driver to send dpd -> Exchange
    Mon Oct 11 20:05:00 2010:Ike: ConRef=156, send_notify_r_u_here - 3d7448fd
    Mon Oct 11 20:05:00 2010:Ike: ConRef=156, NOTIFY : Exchange : SENT : NOTIFY_MSG_R_U_HERE : 36136
    Mon Oct 11 20:05:00 2010:Ike: NOTIFY : Exchange : SENT : NOTIFY_MSG_R_U_HERE : 36136
    Mon Oct 11 20:05:00 2010:Ike: ConRef=156, recv_msg -> setting RealAdapterIndex = 200
    Mon Oct 11 20:05:00 2010:Ike: ConRef=156, NOTIFY : Exchange : RECEIVED : NOTIFY_MSG_R_U_HERE_ACK : 36137
    Mon Oct 11 20:05:00 2010:Ike: NOTIFY : Exchange : RECEIVED : NOTIFY_MSG_R_U_HERE_ACK : 36137
    Mon Oct 11 20:05:00 2010:Ike: ConRef=156, recv_notify_r_u_here_ack - 3d7448fd
    Mon Oct 11 20:05:00 2010:Ike: ConRef=156,  name=Exchange,msg=enter_state_closed - 
      
    Mon Oct 11 20:05:00 2010:IkeQuick: ConRef=156, 
     
    Mon Oct 11 20:05:00 2010:IkeQuick: phase2:name(Exchange) - error - cleared by phase1
    Mon Oct 11 20:05:00 2010:ERROR - 4037: IKE(phase2):Waiting for message2, cleared by phase1 - Exchange.
    Mon Oct 11 20:05:00 2010:IkeQuick: ConRef=156, 
     
    Mon Oct 11 20:05:00 2010:IpsDialCb::enter_closed_state(0)
    Mon Oct 11 20:05:00 2010:IpsDial: linkdown(id = 1)
    Mon Oct 11 20:05:00 2010:IPSec: Disconnected from Exchange on channel 1.
    Mon Oct 11 20:05:00 2010[[:P]]PP(Lcp): linkdown(26b5834)
    Mon Oct 11 20:05:00 2010:BaseCp::enter_closed_state(c021)
    Mon Oct 11 20:05:00 2010[[:P]]PP(Lcp): linkdown exit(26b5834)
    Mon Oct 11 20:05:00 2010:Link: Deleting LwsGateway
    Mon Oct 11 20:05:00 2010:Ike: ConRef=156, send_delete - Exchange
    Mon Oct 11 20:05:00 2010:Ike: ConRef=156, IkeSaDeleted - TotNumIkeSa's=0
    Mon Oct 11 20:05:00 2010:Ike: internal_delikesa[:D]elete phase1(IKE)SA (SpdIndex = 1)
    Mon Oct 11 20:05:02 2010:SockifEx: UdpSocket::RecvThread()Leaving,Port=500
    Mon Oct 11 20:05:03 2010:SockifEx: UdpSocket::RecvThr
Unfiltered HTML