Guest User!

You are not Sophos Staff.

Thread Info
  • State Not Answered
  • Locked Locked
  • Replies 20 replies
  • Subscribers 1 subscriber
  • Views 17897 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

Android 4 & UTM 9 LT2P over IPSEC Pre-shared Key Not Working

jkconnections
About 6 months ago, I was trying to get my VPN access working for both my Android cell phone and my laptop computer. At the time, someone suggested that I try UTM 9 beta, and sure enough that fixed my problems.

Well time has passed and I've since upgraded my Android phone to the Galaxy S3 (Verizon) which is Android 4 based. Also UTM 9 has exited from beta and gone live. It's been a while since I've needed VPN and hadn't tried it since getting the new phone. But sure enough, my Android 4 Galaxy S3 won't connect. 

Since it's been a while since using VPN, I'm uncertain whether this is a problem with my phone, or if one of the many automatic updates broke UTM 9. Before boring you with the log from my phone, I will mention that I am able to successfully put my phone into tether mode, connect my laptop, and use the L2TP/Ipsec PSK connection using Windows XP. So this problem is not an issue with Verizon blocking packets or an incorrect settings in UTM9 (as far as I know). Given that Samsung has already sold 30 million Galaxy S3 phones, I tend to think this is a bug with UTM 9, but I'm certainly willing to entertain the possibility that it's Samsung's fault too. 

Any help would be greatly appreciated as trying to understand these logs is a bit out of my league [:)]

Thanks in advance,

Jonathan


This thread was automatically locked due to age.
  • 0
    Android Log:

    I/Vpn     (  652): Switched from [Legacy VPN] to [Legacy VPN]
    I/Vpn     (  652): Switched from [Legacy VPN] to [Legacy VPN]
    V/LegacyVpnRunner(  652): Waiting
    V/LegacyVpnRunner(  652): Executing
    D/racoon  (20855): Waiting for control socket
    D/racoon  (20855): Received 6 arguments
    I/racoon  (20855): ipsec-tools 0.8.0 (http://ipsec-tools.sf.net)
    I/racoon  (20855): [500] used for NAT-T
    I/racoon  (20855): [500] used as isakmp port (fd=10)
    I/racoon  (20855): [4500] used for NAT-T
    I/racoon  (20855): [4500] used as isakmp port (fd=11)
    D/mtpd    (21157): Waiting for control socket
    D/mtpd    (21157): Received 20 arguments
    I/mtpd    (21157): Using protocol l2tp
    I/mtpd    (21157): Connecting to  port 1701 via rmnet0
    I/mtpd    (21157): Connection established (socket = 11)
    D/mtpd    (21157): Sending SCCRQ (local_tunnel = 54506)
    I/racoon  (20855): IPsec-SA request for  queued due to no phase1 found.
    I/racoon  (20855): initiate new phase 1 negotiation: [500][500]
    I/racoon  (20855): begin Identity Protection mode.
    E/MP-Decision( 1331): DOWN Ld:16 Ns:1.100000 Ts:190 rq:1.000000 seq:196.000000
    I/racoon  (20855): received Vendor ID: CISCO-UNITY
    I/racoon  (20855): received Vendor ID: draft-ietf-ipsra-isakmp-xauth-06.txt
    I/racoon  (20855): received Vendor ID: DPD
    I/racoon  (20855): received Vendor ID: RFC 3947
    I/racoon  (20855): Selected NAT-T version: RFC 3947
    I/racoon  (20855): Hashing [500] with algo #2 
    I/racoon  (20855): Hashing [500] with algo #2 
    I/racoon  (20855): Adding remote and local NAT-D payloads.
    I/racoon  (20855): Hashing [500] with algo #2 
    I/racoon  (20855): NAT-D payload #0 doesn't match
    I/racoon  (20855): Hashing [500] with algo #2 
    I/racoon  (20855): NAT-D payload #1 verified
    I/racoon  (20855): NAT detected: ME 
    I/racoon  (20855): KA list add: [4500]->[4500]
    I/racoon  (20855): ISAKMP-SA established [4500]-[4500] spi:9a6a0bce76bbaef3:907c831d06cbaf88
    I/racoon  (20855): initiate new phase 2 negotiation: [4500][4500]
    I/racoon  (20855): NAT detected -> UDP encapsulation (ENC_MODE 2->4).
    E/racoon  (20855): notification PAYLOAD-MALFORMED received in informational exchange.
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/STATUSBAR-NetworkController(  832): onSignalStrengthsChanged signalStrength=SignalStrength: 99 0 -68 -20 -120 -1 -1 328730 -85 8 88 2147483647 gsm|lte 1284 level=4
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    I/racoon  (20855): IPsec-SA expired: ESP/Transport [500]->[500] spi=40666783(0x26c869f)
    W/racoon  (20855): PF_KEY EXPIRE message received from kernel for SA being negotiated. Stopping negotiation.
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    I/racoon  (20855): initiate new phase 2 negotiation: [4500][4500]
    I/racoon  (20855): NAT detected -> UDP encapsulation (ENC_MODE 2->4).
    E/racoon  (20855): notification PAYLOAD-MALFORMED received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=3
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=2
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=0
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
    E/racoon  (20855): notification INVALID-MESSAGE-ID received in informational exchange.
    I/LegacyVpnRunner(  652): Aborting
    I/LegacyVpnRunner(  652): java.lang.IllegalStateException: Time is up
    I/LegacyVpnRunner(  652): 	at com.android.server.connectivity.Vpn$LegacyVpnRunner.checkpoint(Vpn.java:460)
    I/LegacyVpnRunner(  652): 	at com.android.server.connectivity.Vpn$LegacyVpnRunner.execute(Vpn.java:572)
    I/LegacyVpnRunner(  652): 	at com.android.server.connectivity.Vpn$LegacyVpnRunner.run(Vpn.java:447)
    D/mtpd    (21157): Timeout -> Sending SCCRQ
    I/mtpd    (21157): Received signal 15
    D/mtpd    (21157): Sending STOPCCN
    I/mtpd    (21157): Mtpd is terminated (status = 5)
    E/racoon  (20855): Connection is closed
    I/racoon  (20855): Bye
    D/STATUSBAR-NetworkController(  832): onDataActivity: direction=1
    D/STATUSBAR-NotificationService(  652): cancelNotification - pkg:***.******X.******XX, id:273
  • 0 in reply to jkconnections
    UTM 9 IPSEC Log during Android connection:

    2012:11:10-17:36:42  pluto[5234]: packet from :2504: received Vendor ID payload [RFC 3947]
    2012:11:10-17:36:42  pluto[5234]: packet from :2504: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02]
    2012:11:10-17:36:42  pluto[5234]: packet from :2504: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
    2012:11:10-17:36:42  pluto[5234]: packet from :2504: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
    2012:11:10-17:36:42  pluto[5234]: packet from :2504: ignoring Vendor ID payload [FRAGMENTATION 80000000]
    2012:11:10-17:36:42  pluto[5234]: packet from :2504: received Vendor ID payload [Dead Peer Detection]
    2012:11:10-17:36:42  pluto[5234]: "S_for VPN Users"[5] :2504 #4: responding to Main Mode from unknown peer :2504
    2012:11:10-17:36:43  pluto[5234]: "S_for VPN Users"[5] :2504 #4: NAT-Traversal: Result using RFC 3947: peer is NATed
    2012:11:10-17:36:43  pluto[5234]: "S_for VPN Users"[5] :2504 #4: Peer ID is ID_IPV4_ADDR: '10.170.153.50'
    2012:11:10-17:36:43  pluto[5234]: "S_for VPN Users"[6] :2504 #4: deleting connection "S_for VPN Users"[5] instance with peer  {isakmp=#0/ipsec=#0}
    2012:11:10-17:36:43  pluto[5234]: "S_for VPN Users"[6] :2504 #4: Dead Peer Detection (RFC 3706) enabled
    2012:11:10-17:36:43  pluto[5234]: | NAT-T: new mapping :2504/2508)
    2012:11:10-17:36:43  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sent MR3, ISAKMP SA established
    2012:11:10-17:36:43  pluto[5234]: "S_for VPN Users"[6] :2508 #4: ignoring informational payload, type IPSEC_INITIAL_CONTACT
    2012:11:10-17:36:43  pluto[5234]: "S_for VPN Users"[6] :2508 #4: byte 7 of ISAKMP NAT-OA Payload must be zero, but is not
    2012:11:10-17:36:43  pluto[5234]: "S_for VPN Users"[6] :2508 #4: malformed payload in packet
    2012:11:10-17:36:43  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification PAYLOAD_MALFORMED to :2508
    2012:11:10-17:36:46  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x686a12f2 (perhaps this is a duplicated packet)
    2012:11:10-17:36:46  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:36:49  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x686a12f2 (perhaps this is a duplicated packet)
    2012:11:10-17:36:49  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:36:52  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x686a12f2 (perhaps this is a duplicated packet)
    2012:11:10-17:36:52  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:36:55  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x686a12f2 (perhaps this is a duplicated packet)
    2012:11:10-17:36:55  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:36:58  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x686a12f2 (perhaps this is a duplicated packet)
    2012:11:10-17:36:58  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:01  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x686a12f2 (perhaps this is a duplicated packet)
    2012:11:10-17:37:01  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:04  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x686a12f2 (perhaps this is a duplicated packet)
    2012:11:10-17:37:04  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:07  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x686a12f2 (perhaps this is a duplicated packet)
    2012:11:10-17:37:07  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:10  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0x686a12f2 (perhaps this is a duplicated packet)
    2012:11:10-17:37:10  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:14  pluto[5234]: "S_for VPN Users"[6] :2508 #4: byte 7 of ISAKMP NAT-OA Payload must be zero, but is not
    2012:11:10-17:37:14  pluto[5234]: "S_for VPN Users"[6] :2508 #4: malformed payload in packet
    2012:11:10-17:37:14  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification PAYLOAD_MALFORMED to :2508
    2012:11:10-17:37:18  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xc2426df7 (perhaps this is a duplicated packet)
    2012:11:10-17:37:18  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:20  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xc2426df7 (perhaps this is a duplicated packet)
    2012:11:10-17:37:20  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:23  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xc2426df7 (perhaps this is a duplicated packet)
    2012:11:10-17:37:23  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:26  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xc2426df7 (perhaps this is a duplicated packet)
    2012:11:10-17:37:26  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:29  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xc2426df7 (perhaps this is a duplicated packet)
    2012:11:10-17:37:29  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:32  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xc2426df7 (perhaps this is a duplicated packet)
    2012:11:10-17:37:32  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:36  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xc2426df7 (perhaps this is a duplicated packet)
    2012:11:10-17:37:36  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508
    2012:11:10-17:37:39  pluto[5234]: "S_for VPN Users"[6] :2508 #4: Quick Mode I1 message is unacceptable because it uses a previously used Message ID 0xc2426df7 (perhaps this is a duplicated packet)
    2012:11:10-17:37:39  pluto[5234]: "S_for VPN Users"[6] :2508 #4: sending encrypted notification INVALID_MESSAGE_ID to :2508 
  • 0 in reply to jkconnections
    UTM9 Log when connecting from Windows XP via Android tether: 

    2012:11:10-17:56:01  pluto[5234]: packet from :2521: received Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000004]

    2012:11:10-17:56:01  pluto[5234]: packet from :2521: ignoring Vendor ID payload [FRAGMENTATION]

    2012:11:10-17:56:01  pluto[5234]: packet from :2521: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]

    2012:11:10-17:56:01  pluto[5234]: packet from :2521: ignoring Vendor ID payload [Vid-Initial-Contact]

    2012:11:10-17:56:01  pluto[5234]: "S_for VPN Users"[16] :2521 #16: responding to Main Mode from unknown peer :2521

    2012:11:10-17:56:02  pluto[5234]: "S_for VPN Users"[16] :2521 #16: NAT-Traversal: Result using draft-ietf-ipsec-nat-t-ike-02/03: peer is NATed

    2012:11:10-17:56:02  pluto[5234]: "S_for VPN Users"[16] :2521 #16: Peer ID is ID_FQDN: 'jonathan-laptop'

    2012:11:10-17:56:02  pluto[5234]: "S_for VPN Users"[17] :2521 #16: deleting connection "S_for VPN Users"[16] instance with peer  {isakmp=#0/ipsec=#0}

    2012:11:10-17:56:02  pluto[5234]: | NAT-T: new mapping :2521/2511)

    2012:11:10-17:56:02  pluto[5234]: "S_for VPN Users"[17] :2511 #16: sent MR3, ISAKMP SA established

    2012:11:10-17:56:02  pluto[5234]: "S_for VPN Users"[7] :2511 #17: responding to Quick Mode

    2012:11:10-17:56:02  openl2tpd[5186]: FUNC: tunl 1783: allocated context using profile 'default', created by network request

    2012:11:10-17:56:02  openl2tpd[5186]: PROTO: tunl 1783: SCCRQ received from peer 5

    2012:11:10-17:56:02  openl2tpd[5186]: FSM: CCE(1783) event SCCRQ_ACCEPT in state IDLE

    2012:11:10-17:56:02  openl2tpd[5186]: PROTO: tunl 1783: adjust tx_window_size: peer=8, ours=10

    2012:11:10-17:56:02  openl2tpd[5186]: PROTO: tunl 1783: sending SCCRP to peer 5

    2012:11:10-17:56:02  openl2tpd[5186]: FSM: CCE(1783) state change: IDLE --> WAITCTLCONN

    2012:11:10-17:56:02  openl2tpd[5186]: PROTO: tunl 1783: SCCCN received from peer 5

    2012:11:10-17:56:02  openl2tpd[5186]: FSM: CCE(1783) event SCCCN_ACCEPT in state WAITCTLCONN

    2012:11:10-17:56:02  openl2tpd[5186]: FUNC: tunl 1783 up

    2012:11:10-17:56:02  openl2tpd[5186]: FSM: CCE(1783) state change: WAITCTLCONN --> ESTABLISHED

    2012:11:10-17:56:02  openl2tpd[5186]: PROTO: tunl 1783/0: ICRQ received from peer 5

    2012:11:10-17:56:02  openl2tpd[5186]: PROTO: tunl 1783/22842: sending ICRP to peer 5/1

    2012:11:10-17:56:02  pluto[5234]: "S_for VPN Users"[7] :2511 #17: IPsec SA established {ESP=>0x2c023079  openl2tpd[5186]: PROTO: tunl 1783/22842: ICCN received from peer 5

    2012:11:10-17:56:02  pppd-l2tp[8923]: Plugin aua.so loaded.

    2012:11:10-17:56:02  pppd-l2tp[8923]: AUA plugin initialized.

    2012:11:10-17:56:02  pppd-l2tp[8923]: Plugin ippool.so loaded.

    2012:11:10-17:56:02  pppd-l2tp[8923]: Plugin pppol2tp.so loaded.

    2012:11:10-17:56:02  pppd-l2tp[8923]: pppd 2.4.5 started by (unknown), uid 0

    2012:11:10-17:56:02  pppd-l2tp[8923]: using channel 4

    2012:11:10-17:56:02  pppd-l2tp[8923]: Using interface ppp0

    2012:11:10-17:56:02  pppd-l2tp[8923]: Connect: ppp0 

    2012:11:10-17:56:02  pppd-l2tp[8923]: Overriding mtu 1500 to 1380

    2012:11:10-17:56:02  pppd-l2tp[8923]: PPPoL2TP options: lnsmode tid 1783 sid 22842 debugmask 0

    2012:11:10-17:56:02  pppd-l2tp[8923]: Overriding mru 1500 to mtu value 1380

    2012:11:10-17:56:02  pppd-l2tp[8923]: sent [LCP ConfReq id=0x1    ]

    2012:11:10-17:56:03  pppd-l2tp[8923]: rcvd [LCP ConfAck id=0x1    ]

    2012:11:10-17:56:04  pppd-l2tp[8923]: rcvd [LCP ConfReq id=0x1     ]

    2012:11:10-17:56:04  pppd-l2tp[8923]: sent [LCP ConfRej id=0x1 ]

    2012:11:10-17:56:05  pppd-l2tp[8923]: rcvd [LCP ConfReq id=0x2    ]

    2012:11:10-17:56:05  pppd-l2tp[8923]: sent [LCP ConfAck id=0x2    ]

    2012:11:10-17:56:05  pppd-l2tp[8923]: Overriding mtu 1400 to 1380

    2012:11:10-17:56:05  pppd-l2tp[8923]: PPPoL2TP options: lnsmode tid 1783 sid 22842 debugmask 0

    2012:11:10-17:56:05  pppd-l2tp[8923]: sent [CHAP Challenge id=0xee , name = ""]

    2012:11:10-17:56:05  pppd-l2tp[8923]: rcvd [LCP Ident id=0x3 magic=0x5b8f04d2 "MSRASV5.10"]

    2012:11:10-17:56:05  pppd-l2tp[8923]: rcvd [LCP Ident id=0x4 magic=0x5b8f04d2 "MSRAS-0-JONATHAN-LAPTOP"]

    2012:11:10-17:56:05  pppd-l2tp[8923]: rcvd [CHAP Response id=0xee , name = ""]

    2012:11:10-17:56:07  pppd-l2tp[8923]: AUAconnect - Returned IPAddr *

    2012:11:10-17:56:07  pppd-l2tp[8923]: AUA: authentication of user  succeeded

    2012:11:10-17:56:07  pppd-l2tp[8923]: sent [CHAP Success id=0xee "S=6F812B1E992DAE0EB95DE7CA52C8ED651B5B1EAB M=Access granted"]

    2012:11:10-17:56:07  pppd-l2tp[8923]: sent [IPCP ConfReq id=0x1 ]

    2012:11:10-17:56:08  pppd-l2tp[8923]: rcvd [CHAP Response id=0xee , name = ""]

    2012:11:10-17:56:08  pppd-l2tp[8923]: sent [CHAP Success id=0xee "S=6F812B1E992DAE0EB95DE7CA52C8ED651B5B1EAB M=Access granted"]

    2012:11:10-17:56:08  pppd-l2tp[8923]: rcvd [CCP ConfReq id=0x5 ]

    2012:11:10-17:56:08  pppd-l2tp[8923]: Unsupported protocol 'Compression Control Protocol' (0x80fd) received

    2012:11:10-17:56:08  pppd-l2tp[8923]: sent [LCP ProtRej id=0x2 80 fd 01 05 00 0a 12 06 01 00 00 01]

    2012:11:10-17:56:08  pppd-l2tp[8923]: rcvd [IPCP ConfReq id=0x6     ]

    2012:11:10-17:56:08  pppd-l2tp[8923]: sent [IPCP ConfRej id=0x6  ]

    2012:11:10-17:56:08  pppd-l2tp[8923]: rcvd [IPCP ConfReq id=0x7   ]

    2012:11:10-17:56:08  pppd-l2tp[8923]: sent [IPCP ConfNak id=0x7   ]

    2012:11:10-17:56:08  pppd-l2tp[8923]: rcvd [IPCP ConfReq id=0x8   ]

    2012:11:10-17:56:08  pppd-l2tp[8923]: sent [IPCP ConfAck id=0x8   ]

    2012:11:10-17:56:10  pppd-l2tp[8923]: sent [IPCP ConfReq id=0x1 ]

    2012:11:10-17:56:10  pppd-l2tp[8923]: rcvd [IPCP ConfAck id=0x1 ]

    2012:11:10-17:56:10  pppd-l2tp[8923]: Cannot determine ethernet address for proxy ARP

    2012:11:10-17:56:10  pppd-l2tp[8923]: local IP address 10.242.3.1

    2012:11:10-17:56:10  pppd-l2tp[8923]: remote IP address 10.242.3.2

    2012:11:10-17:56:10  pppd-l2tp[8923]: Script /etc/ppp/ip-up started (pid 8932)

    2012:11:10-17:56:10  pppd-l2tp[8923]: id="2201" severity="info" sys="SecureNet" sub="vpn" event="Connection started" username="" variant="l2tp" srcip="" virtual_ip="10.242.3.2"

    2012:11:10-17:56:10  pppd-l2tp[8923]: Script /etc/ppp/ip-up finished (pid 8932), status = 0x0 
  • 0
    It must be somthing unique to the new Android OS.  Is anyone having this problem with other Remote Access Servers?

    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
    It must be somthing unique to the new Android OS.  Is anyone having this problem with other Remote Access Servers?

    Cheers - Bob


    Thanks, Bob! So I've continued to do some digging on this since my last posts and I ran across an interesting webpage. A lot of this is out of my leauge, but I'll do my best to summarize. If I understand this correctly, apparently there are two different linux tools that can be used to implement a VPN on a linux box (such as UTM9) - one is openswan and the other is ipsec-tools. Android 4 uses ipsec-tools verion 0.8.0, so I'm guessing UTM 9 must be using openswan. Apparently the problem is in ipsec-tools 0.8.0 whereas previous version of Android used an older version of ipsec-tools that didn't have the issue. So it looks like anyone who has Android 4 (Ice Creame Sandwhich) will not be able to use VPN. It was unclear to me whether Android 4.1 fixes the issue. Some users said it did, others it wasn't so clear. 

    TheGoogle page I link to below does list several apps that people said might fix the problem, but I'm honestly a bit confused by all the options as they aren't as clear as the ones in the system menu where I normally setup VPN. For example, the OpenVPN app gives me the following options, but I'm not sure which one is euqal to IPSEC/PSK:   Android Certificate, Username/Password, Static Keys, User/PW + Certificates, User/PW+PKCS12, User/PW + Android.

    Do you have any idea which one of those options I would want to connect to UTM 9 using a preshared key?

    By the way, here are the links if anyone is interested in reading up on this:

    Page of users discussing the bug:
    Issue 23124 - android - Can't connect to VPN (nexus s - ice cream sandwich) - Android - An Open Handset Alliance Project - Google Project Hosting

    This user created a modified version of racoon for Android that he said should fix the issue. Issue 23124 - android - Can't connect to VPN (nexus s - ice cream sandwich) - Android - An Open Handset Alliance Project - Google Project Hosting But it requires the Android SDK (and a rooted phone), so I'll have to install that at some point to see if that works for me (unless I just wait for Anroid 4.1 Jelly Bean to see if that fixes the issue as that should be here in a couple of weeks). 

    This person describes how to set up a VPN based on ipsec-tools instead of openswan:

    L2TP/IPSec VPN Setup on Centos 6 (64-bit) for use with Android ICS and iOS 5 Clients - Nikoforge Wiki
  • 0
    Jonathan,

    I think we'll need to wait for one of the VPN devs to see this.  The IPsec server in the UTM is based on StrongSWAN.  You might try strongSwan - strongSwan VPN Client for Android 4+ and let the rest of us know if that worked for you.  I guess that's an IPsec client, not an L2TP/IPsec one.

    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
    Unless I had one of the UTM 9 Remote Access>IPSEC settings wrong (I wasn't sure which policy or authentication settings to use) or did something wrong in the StrongSwan app, it didn't work. [:(]

    Here's the log from the StrongSwan app: 

    Nov 12 12:56:01 00[DMN] Starting IKE charon daemon (strongSwan 5.0.1, Linux 3.0.8-1092717, armv7l)

    Nov 12 12:56:01 00[DMN] loaded plugins: androidbridge charon android-log openssl fips-prf random nonce pubkey pkcs1 pkcs8 pem xcbc hmac socket-default eap-identity eap-mschapv2 eap-md5 eap-gtc

    Nov 12 12:56:01 00[JOB] spawning 16 worker threads

    Nov 12 12:56:01 07[CFG] loaded user certificate 'C=us, L=Greenville, SC, O=Jonathan, CN=Jonathan, E=' and private key

    Nov 12 12:56:01 07[CFG] loaded CA certificate 'C=us, L=Greenville, SC, O=Jonathan, CN=Jonathan VPN CA, E='

    Nov 12 12:56:02 07[IKE] initiating IKE_SA android[4] to 

    Nov 12 12:56:02 07[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]

    Nov 12 12:56:02 07[NET] sending packet: from [56425] to [500]

    Nov 12 12:56:04 10[IKE] retransmit 1 of request with message ID 0

    Nov 12 12:56:04 10[NET] sending packet: from [56425] to [500]

    Nov 12 12:56:07 11[IKE] retransmit 2 of request with message ID 0

    Nov 12 12:56:07 11[NET] sending packet: from [56425] to [500]

    Nov 12 12:56:11 12[IKE] retransmit 3 of request with message ID 0

    Nov 12 12:56:11 12[NET] sending packet: from [56425] to [500]

    Nov 12 12:56:16 13[IKE] giving up after 3 retransmits

    Nov 12 12:56:16 13[IKE] peer not responding, trying again (2/0)

    Nov 12 12:56:16 13[IKE] initiating IKE_SA android[4] to 

    Nov 12 12:56:16 13[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]

    Nov 12 12:56:16 13[NET] sending packet: from [56425] to [500]

    Nov 12 12:56:16 00[IKE] destroying IKE_SA in state CONNECTING without notification
  • 0
    How about the log from the UTM.  If you have debugging enabled, please disable that and record just the regular conversation.

    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
    How about the log from the UTM.  If you have debugging enabled, please disable that and record just the regular conversation.


    The IPSEC VPN Live log is where I got the log when trying to use LT2P/IPSEC PSK. Is this the same spot I should be looking for the regular IPSEC log? If so, no logs are being recorded on UTM 9 when I try to connect using the app over 4G (I don't have access to wi-fi for my phone where I am currently). Could Verizon be blocking the packets?

    My settings in the android app are:
    Gateway: 
    Type: IKEv2 Certificate (the other option is IKEv2 EAP (Username/Password) - but that option doesn't seem to work either).
    User Certificate: the user certificate from UTM 9 that I'm trying to connect with
    CA certificate: select automatically is checked.


    It fails with the message: Failed to establish VPN: Gateway is unreachable.
  • 0
    Have you considered setting it up with the Cisco IPSec instead of encapsulation with L2TP?  I have it working on Android 4.1.2. See here:

    https://community.sophos.com/products/unified-threat-management/astaroorg/f/58/t/54709
Share Feedback
×

Submitted a Tech Support Case lately from the Support Portal?

Unfiltered HTML