Guest User!

You are not Sophos Staff.

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

Android VPN L2TP/IPSEC PSK Doesn't Connect

I'm having trouble connecting my Android 2.3.5 phone to my Astaro box. I'm able connect Windows machines to Astaro using a preshared key just fine, but Android doesn't work. I'm running Astaro 8.302.

My network is as follows:
Modem (in bridged mode) --> Astaro Box

L2TP/IPSEC settings:
Interface: External
Authentication: Preshared key
Assign IP Address: IP Address Pool
Pool Network: VPN Pool (L2TP)

Firewall:
Source: VPN Pool (L2TP)
Service: Any
Destination: Internal Network

NAT Masquerading Rule:
VPN Pool (L2TP) --> External (Bottom position)


I know how to retrieve the logs, but I don't know enough to be able to diagnose the problem just by reading the logs. Does anyone have any suggestions on what I need to do? 

Here's a copy of the IPSEC log from Astaro (Android IP is removed):


2012:05:07-08:32:24 sqlguy pppd-l2tp[23587]: rcvd [LCP TermReq id=0x8 "R_oD\000:6137: received Vendor ID payload [RFC 3947]
2012:05:07-08:32:48 sqlguy pluto[15886]: packet from :6137: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02]
2012:05:07-08:32:48 sqlguy pluto[15886]: packet from :6137: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
2012:05:07-08:32:48 sqlguy pluto[15886]: packet from :6137: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
2012:05:07-08:32:48 sqlguy pluto[15886]: packet from :6137: ignoring Vendor ID payload [FRAGMENTATION 80000000]
2012:05:07-08:32:48 sqlguy pluto[15886]: "S_REF_IpsL2t1_1"[9] :6137 #21: responding to Main Mode from unknown peer :6137
2012:05:07-08:32:49 sqlguy pluto[15886]: "S_REF_IpsL2t1_1"[9] :6137 #21: NAT-Traversal: Result using RFC 3947: peer is NATed
2012:05:07-08:32:49 sqlguy pluto[15886]: "S_REF_IpsL2t1_1"[9] :6137 #21: Peer ID is ID_IPV4_ADDR: '10.247.1.177'
2012:05:07-08:32:49 sqlguy pluto[15886]: "S_REF_IpsL2t1_1"[10] :6137 #21: deleting connection "S_REF_IpsL2t1_1"[9] instance with peer  {isakmp=#0/ipsec=#0}
2012:05:07-08:32:49 sqlguy pluto[15886]: | NAT-T: new mapping :6137/6131)
2012:05:07-08:32:49 sqlguy pluto[15886]: "S_REF_IpsL2t1_1"[10] :6131 #21: sent MR3, ISAKMP SA established
2012:05:07-08:32:49 sqlguy pluto[15886]: "S_REF_IpsL2t1_1"[10] :6131 #21: ignoring informational payload, type IPSEC_INITIAL_CONTACT
2012:05:07-08:32:50 sqlguy pluto[15886]: "S_REF_IpsL2t1_0"[5] :6131 #22: responding to Quick Mode
2012:05:07-08:32:50 sqlguy pluto[15886]: "S_REF_IpsL2t1_0"[5] :6131 #22: IPsec SA established {ESP=>0x09ee6096 


This thread was automatically locked due to age.
Parents
  • Not sure if this will be helpful, but here is a copy of my Android phone's log from alogcat (with my home IP removed):


    D/VpnSettings(12908): received connectivity: JDK Home: connected? CONNECTING   err=0
    D/SProxy_racoon(16268): racoon is stopped after 0 msec
    D/SProxy_racoon(16268): stopping racoon, success? true
    D/VpnService(16268):   Local IP: 10.247.1.177, if: ppp0
    I/StatusBarManagerService(  106): REMOVE-JDK Home VPN disconnected , 0x7f020001
    D/VpnService(16268):        VPN UP: down
    I/SProxy_racoon(16268): Start VPN daemon: racoon
    D/SProxy_racoon(16268): racoon is running after 0 msec
    D/SProxy_racoon(16268): service not yet listen()ing; try again
    D/racoon  (16699): Waiting for control socket
    D/racoon  (16699): Received 3 arguments
    I/racoon  (16699): ipsec-tools 0.7.3 (http://ipsec-tools.sf.net)
    I/racoon  (16699): 10.247.1.177[500] used as isakmp port (fd=10)
    I/racoon  (16699): 10.247.1.177[500] used for NAT-T
    I/racoon  (16699): 10.247.1.177[4500] used as isakmp port (fd=11)
    I/racoon  (16699): 10.247.1.177[4500] used for NAT-T
    I/SProxy_racoon(16268): got data from control socket: 3
    I/SProxy_mtpd(16268): Start VPN daemon: mtpd
    D/mtpd    (17021): Waiting for control socket
    D/SProxy_mtpd(16268): mtpd is running after 0 msec
    D/mtpd    (17021): Received 19 arguments
    I/mtpd    (17021): Using protocol l2tp
    I/mtpd    (17021): Connecting to  port 1701
    I/mtpd    (17021): Connection established (socket = 11)
    D/mtpd    (17021): Sending SCCRQ (local_tunnel = 24367)
    I/racoon  (16699): no in-bound policy found: /32[1701] 10.247.1.177/32[0] proto=udp dir=in
    I/racoon  (16699): IPsec-SA request for  queued due to no phase1 found.
    I/racoon  (16699): initiate new phase 1 negotiation: 10.247.1.177[500][500]
    I/racoon  (16699): begin Identity Protection mode.
    I/SProxy_mtpd(16268): got data from control socket: 19
    I/racoon  (16699): received Vendor ID: CISCO-UNITY
    I/racoon  (16699): received Vendor ID: draft-ietf-ipsra-isakmp-xauth-06.txt
    I/racoon  (16699): received Vendor ID: DPD
    I/racoon  (16699): received Vendor ID: RFC 3947
    I/racoon  (16699): Selected NAT-T version: RFC 3947
    I/racoon  (16699): Hashing [500] with algo #2 
    I/racoon  (16699): Hashing 10.247.1.177[500] with algo #2 
    I/racoon  (16699): Adding remote and local NAT-D payloads.
    I/racoon  (16699): Hashing 10.247.1.177[500] with algo #2 
    I/racoon  (16699): NAT-D payload #0 doesn't match
    I/racoon  (16699): Hashing [500] with algo #2 
    I/racoon  (16699): NAT-D payload #1 verified
    I/racoon  (16699): NAT detected: ME 
    I/racoon  (16699): KA list add: 10.247.1.177[4500]->[4500]
    I/keystore(   75): uid: 1016 action: g -> 1 state: 1 -> 1 retry: 4
    I/racoon  (16699): ISAKMP-SA established 10.247.1.177[4500]-[4500] spi[:D]7faaacd0dc46d16:36cf269e18863c70
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    I/racoon  (16699): initiate new phase 2 negotiation: 10.247.1.177[4500][4500]
    I/racoon  (16699): NAT detected -> UDP encapsulation (ENC_MODE 2->4).
    I/racoon  (16699): Adjusting my encmode UDP-Transport->Transport
    I/racoon  (16699): Adjusting peer's encmode UDP-Transport(4)->Transport(2)
    I/racoon  (16699): IPsec-SA established: ESP/Transport [0]->10.247.1.177[0] spi=241882039(0xe6ad3b7)
    I/racoon  (16699): IPsec-SA established: ESP/Transport 10.247.1.177[4500]->[4500] spi=2636481733(0x9d2584c5)
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    E/VpnService(16268): onError()
    E/VpnService(16268): java.io.IOException: Connecting timed out
    E/VpnService(16268):  at com.android.server.vpn.VpnService.waitUntilConnectedOrTimedout(VpnService.java:206)
    E/VpnService(16268):  at com.android.server.vpn.VpnService.onConnect(VpnService.java:136)
    E/VpnService(16268):  at com.android.server.vpn.VpnServiceBinder$2.run(VpnServiceBinder.java:117)
    E/VpnService(16268):  at java.lang.Thread.run(Thread.java:1019)
    I/VpnService(16268): disconnecting VPN...
    D/VpnSettings(12908): received connectivity: JDK Home: connected? DISCONNECTING   err=0
    I/StatusBarManagerService(  106): ADD-JDK Home VPN disconnected , 0x7f020001
    I/SProxy_mtpd(16268): Stop VPN daemon: mtpd
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    I/mtpd    (17021): Received signal 15
    D/mtpd    (17021): Sending STOPCCN
    I/mtpd    (17021): Mtpd is terminated (status = 6)
    D/SProxy_mtpd(16268): mtpd is stopped after 0 msec
    D/SProxy_mtpd(16268): stopping mtpd, success? true
    I/SProxy_racoon(16268): Stop VPN daemon: racoon
    I/racoon  (16699): Bye
    D/SProxy_racoon(16268): racoon is stopped after 0 msec
    D/SProxy_racoon(16268): stopping racoon, success? true
    D/VpnService(16268): onFinalCleanUp()
    I/VpnService(16268): restore original suffices --> null
    D/VpnSettings(12908): received connectivity: JDK Home: connected? IDLE   err=101
Reply
  • Not sure if this will be helpful, but here is a copy of my Android phone's log from alogcat (with my home IP removed):


    D/VpnSettings(12908): received connectivity: JDK Home: connected? CONNECTING   err=0
    D/SProxy_racoon(16268): racoon is stopped after 0 msec
    D/SProxy_racoon(16268): stopping racoon, success? true
    D/VpnService(16268):   Local IP: 10.247.1.177, if: ppp0
    I/StatusBarManagerService(  106): REMOVE-JDK Home VPN disconnected , 0x7f020001
    D/VpnService(16268):        VPN UP: down
    I/SProxy_racoon(16268): Start VPN daemon: racoon
    D/SProxy_racoon(16268): racoon is running after 0 msec
    D/SProxy_racoon(16268): service not yet listen()ing; try again
    D/racoon  (16699): Waiting for control socket
    D/racoon  (16699): Received 3 arguments
    I/racoon  (16699): ipsec-tools 0.7.3 (http://ipsec-tools.sf.net)
    I/racoon  (16699): 10.247.1.177[500] used as isakmp port (fd=10)
    I/racoon  (16699): 10.247.1.177[500] used for NAT-T
    I/racoon  (16699): 10.247.1.177[4500] used as isakmp port (fd=11)
    I/racoon  (16699): 10.247.1.177[4500] used for NAT-T
    I/SProxy_racoon(16268): got data from control socket: 3
    I/SProxy_mtpd(16268): Start VPN daemon: mtpd
    D/mtpd    (17021): Waiting for control socket
    D/SProxy_mtpd(16268): mtpd is running after 0 msec
    D/mtpd    (17021): Received 19 arguments
    I/mtpd    (17021): Using protocol l2tp
    I/mtpd    (17021): Connecting to  port 1701
    I/mtpd    (17021): Connection established (socket = 11)
    D/mtpd    (17021): Sending SCCRQ (local_tunnel = 24367)
    I/racoon  (16699): no in-bound policy found: /32[1701] 10.247.1.177/32[0] proto=udp dir=in
    I/racoon  (16699): IPsec-SA request for  queued due to no phase1 found.
    I/racoon  (16699): initiate new phase 1 negotiation: 10.247.1.177[500][500]
    I/racoon  (16699): begin Identity Protection mode.
    I/SProxy_mtpd(16268): got data from control socket: 19
    I/racoon  (16699): received Vendor ID: CISCO-UNITY
    I/racoon  (16699): received Vendor ID: draft-ietf-ipsra-isakmp-xauth-06.txt
    I/racoon  (16699): received Vendor ID: DPD
    I/racoon  (16699): received Vendor ID: RFC 3947
    I/racoon  (16699): Selected NAT-T version: RFC 3947
    I/racoon  (16699): Hashing [500] with algo #2 
    I/racoon  (16699): Hashing 10.247.1.177[500] with algo #2 
    I/racoon  (16699): Adding remote and local NAT-D payloads.
    I/racoon  (16699): Hashing 10.247.1.177[500] with algo #2 
    I/racoon  (16699): NAT-D payload #0 doesn't match
    I/racoon  (16699): Hashing [500] with algo #2 
    I/racoon  (16699): NAT-D payload #1 verified
    I/racoon  (16699): NAT detected: ME 
    I/racoon  (16699): KA list add: 10.247.1.177[4500]->[4500]
    I/keystore(   75): uid: 1016 action: g -> 1 state: 1 -> 1 retry: 4
    I/racoon  (16699): ISAKMP-SA established 10.247.1.177[4500]-[4500] spi[:D]7faaacd0dc46d16:36cf269e18863c70
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    I/racoon  (16699): initiate new phase 2 negotiation: 10.247.1.177[4500][4500]
    I/racoon  (16699): NAT detected -> UDP encapsulation (ENC_MODE 2->4).
    I/racoon  (16699): Adjusting my encmode UDP-Transport->Transport
    I/racoon  (16699): Adjusting peer's encmode UDP-Transport(4)->Transport(2)
    I/racoon  (16699): IPsec-SA established: ESP/Transport [0]->10.247.1.177[0] spi=241882039(0xe6ad3b7)
    I/racoon  (16699): IPsec-SA established: ESP/Transport 10.247.1.177[4500]->[4500] spi=2636481733(0x9d2584c5)
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    E/VpnService(16268): onError()
    E/VpnService(16268): java.io.IOException: Connecting timed out
    E/VpnService(16268):  at com.android.server.vpn.VpnService.waitUntilConnectedOrTimedout(VpnService.java:206)
    E/VpnService(16268):  at com.android.server.vpn.VpnService.onConnect(VpnService.java:136)
    E/VpnService(16268):  at com.android.server.vpn.VpnServiceBinder$2.run(VpnServiceBinder.java:117)
    E/VpnService(16268):  at java.lang.Thread.run(Thread.java:1019)
    I/VpnService(16268): disconnecting VPN...
    D/VpnSettings(12908): received connectivity: JDK Home: connected? DISCONNECTING   err=0
    I/StatusBarManagerService(  106): ADD-JDK Home VPN disconnected , 0x7f020001
    I/SProxy_mtpd(16268): Stop VPN daemon: mtpd
    D/mtpd    (17021): Timeout -> Sending SCCRQ
    I/mtpd    (17021): Received signal 15
    D/mtpd    (17021): Sending STOPCCN
    I/mtpd    (17021): Mtpd is terminated (status = 6)
    D/SProxy_mtpd(16268): mtpd is stopped after 0 msec
    D/SProxy_mtpd(16268): stopping mtpd, success? true
    I/SProxy_racoon(16268): Stop VPN daemon: racoon
    I/racoon  (16699): Bye
    D/SProxy_racoon(16268): racoon is stopped after 0 msec
    D/SProxy_racoon(16268): stopping racoon, success? true
    D/VpnService(16268): onFinalCleanUp()
    I/VpnService(16268): restore original suffices --> null
    D/VpnSettings(12908): received connectivity: JDK Home: connected? IDLE   err=101
Children
No Data