Problem with l2tp on mpd5+ipsec

I

ilemur

Freebsd FreeBSD 9.2. Using Android 4.3 to connect from a GSM network with no luck. Kernel was compiled with the following:

Code: 
include         GENERIC
ident            WHY21

#PF and QOS
device          pf
device          pflog
device          pfsync
options         ALTQ
options         ALTQ_CBQ
options         ALTQ_RED
options         ALTQ_RIO
options         ALTQ_HFSC
options         ALTQ_PRIQ
options         ALTQ_NOPCC

#IPSEC
options         IPSEC
options         IPSEC_NAT_T
options         IPSEC_DEBUG
device          crypto
Then for simplicity made for testing purposes like this:
/etc/pf.conf
Code: 
ext_if="dc0"
int_if="msk0"
vpn_if="{ ng0, ng1 }"
why="192.168.1.0/24"

nat on $ext_if from $why to any -> ($ext_if)
pass quick all

/usr/local/etc/mpd5/mpd.conf:
Code: 
startup:
        #configure mpd users
        set user login pass admin
        #configure the console
        set console self 127.0.0.1 5005
        set console open
        #configure web server
        #set web disable auth
        set web self 192.168.1.3 5006
        set web open
default:
        load whyers_vpn

whyers_vpn:
        set ippool add poolsat 192.168.1.200 192.168.1.220
        create bundle template B
        set iface enable proxy-arp
        set iface idle 1800
        set iface enable tcpmssfix
        set ipcp yes vjcomp
        set ipcp ranges 192.168.1.200/24 ippool poolsat
        set ipcp dns 192.168.1.3
        
        create link template L l2tp
        set link action bundle B
        set link enable multilink
        set link yes acfcomp protocomp
        set link no pap chap
        set link enable chap
        set l2tp enable length
        set link keep-alive 10 60
        set link mtu 1460
        set l2tp self 0.0.0.0
        set link enable incoming

/usr/local/etc/racoon/racoon.conf:
Code: 
path pre_shared_key "/usr/local/etc/racoon/psk.txt";
log info;

#listen
#{
#        isakmp           192.168.0.1 [500];
#        isakmp_natt      192.168.0.1 [4500];
#        strict_address;
#}

remote anonymous
{
        exchange_mode    aggressive,main;
        passive          on;
        proposal_check   obey;
        support_proxy    on;
        nat_traversal    on;
        ike_frag         on;
        dpd_delay        30;
        generate_policy  on;
        proposal
        {
                encryption_algorithm  aes;
                hash_algorithm        sha1;
                authentication_method pre_shared_key;
                dh_group              modp1024;
        }

        proposal
        {
                encryption_algorithm  3des;
                hash_algorithm        sha1;
                authentication_method pre_shared_key;
                dh_group              modp1024;
        }
}

sainfo anonymous
{
        encryption_algorithm     aes,3des;
        authentication_algorithm hmac_sha1;
        compression_algorithm    deflate;
        pfs_group                modp1024;
}

setkey.conf:
Code: 
flush;
spdflush;
spdadd 0.0.0.0/0[0] 0.0.0.0/0[1701] udp -P in  ipsec esp/transport//require;
spdadd 0.0.0.0/0[1701] 0.0.0.0/0[0] udp -P out ipsec esp/transport//require;

Results:

racoon.log without debug2:

Code: 
2013-10-24 19:40:15: INFO: respond new phase 1 negotiation: SERVER.IP[500]<=>ANDROID.IP[57577]
2013-10-24 19:40:15: INFO: begin Identity Protection mode.
2013-10-24 19:40:15: INFO: received Vendor ID: RFC 3947
2013-10-24 19:40:15: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02
2013-10-24 19:40:15: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02

2013-10-24 19:40:15: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-00
2013-10-24 19:40:15: INFO: received broken Microsoft ID: FRAGMENTATION
2013-10-24 19:40:15: INFO: received Vendor ID: DPD
2013-10-24 19:40:15: [ANDROID.IP] INFO: Selected NAT-T version: RFC 3947
2013-10-24 19:40:16: [SERVER.IP] INFO: Hashing SERVER.IP[500] with algo #2
2013-10-24 19:40:16: INFO: NAT-D payload #0 verified
2013-10-24 19:40:16: [ANDROID.IP] INFO: Hashing ANDROID.IP[57577] with algo #2
2013-10-24 19:40:16: INFO: NAT-D payload #1 doesn't match
2013-10-24 19:40:16: INFO: NAT detected: PEER
2013-10-24 19:40:16: [ANDROID.IP] INFO: Hashing ANDROID.IP[57577] with algo #2
2013-10-24 19:40:16: [SERVER.IP] INFO: Hashing SERVER.IP[500] with algo #2
2013-10-24 19:40:16: INFO: Adding remote and local NAT-D payloads.
2013-10-24 19:40:17: INFO: NAT-T: ports changed to: ANDROID.IP[57833]<->SERVER.IP[4500]
2013-10-24 19:40:17: INFO: KA list add: SERVER.IP[4500]->ANDROID.IP[57833]
2013-10-24 19:40:17: INFO: ISAKMP-SA established SERVER.IP[4500]-ANDROID.IP[57833] spi:311fa45f4ea77921:536427825b92cc3e
2013-10-24 19:40:18: [ANDROID.IP] INFO: received INITIAL-CONTACT
2013-10-24 19:40:18: INFO: respond new phase 2 negotiation: SERVER.IP[4500]<=>ANDROID.IP[57833]
2013-10-24 19:40:18: INFO: Update the generated policy : 10.218.130.252/32[0] SERVER.IP/32[1701] proto=udp dir=in
2013-10-24 19:40:18: INFO: Adjusting my encmode UDP-Transport->Transport
2013-10-24 19:40:18: INFO: Adjusting peer's encmode UDP-Transport(4)->Transport(2)
2013-10-24 19:40:19: INFO: IPsec-SA established: ESP/Transport SERVER.IP[500]->ANDROID.IP[500] spi=253884309(0xf21f795)
2013-10-24 19:40:19: INFO: IPsec-SA established: ESP/Transport SERVER.IP[500]->ANDROID.IP[500] spi=8896613(0x87c065)

and with debug2 (only the tail):

Code: 
2013-10-24 19:52:25: DEBUG: hmac(hmac_sha1)
2013-10-24 19:52:25: DEBUG: HASH computed:
2013-10-24 19:52:25: DEBUG:
dea64457 b1881007 797cf9a1 4c9a6f56 2b90e9ee
2013-10-24 19:52:25: DEBUG: begin encryption.
2013-10-24 19:52:25: DEBUG: encryption(aes)
2013-10-24 19:52:25: DEBUG: pad length = 8
2013-10-24 19:52:25: DEBUG:
Here were somenumbers with hash. Removed it (author of the thread)
2013-10-24 19:52:25: DEBUG: encryption(aes)
2013-10-24 19:52:25: DEBUG: with key:
2013-10-24 19:52:25: DEBUG:
Here were somenumbers with hash. Removed it (author of the thread)
2013-10-24 19:52:25: DEBUG: encrypted payload by IV:
2013-10-24 19:52:25: DEBUG:
Here were somenumbers with hash. Removed it (author of the thread)
2013-10-24 19:52:25: DEBUG: save IV for next:
2013-10-24 19:52:25: DEBUG:
Here were somenumbers with hash. Removed it (author of the thread)
2013-10-24 19:52:25: DEBUG: encrypted.
2013-10-24 19:52:25: DEBUG: Adding NON-ESP marker
2013-10-24 19:52:25: DEBUG: 96 bytes from SERVER.IP[4500] to ANDROID.IP[9826]
2013-10-24 19:52:25: DEBUG: sockname SERVER.IP[4500]
2013-10-24 19:52:25: DEBUG: send packet from SERVER.IP[4500]
2013-10-24 19:52:25: DEBUG: send packet to ANDROID.IP[9826]
2013-10-24 19:52:25: DEBUG: 1 times of 96 bytes message will be sent to ANDROID.IP[9826]
2013-10-24 19:52:25: DEBUG:
Here were somenumbers with hash. Removed it (author of the thread)
2013-10-24 19:52:25: DEBUG: sendto Information notify.
2013-10-24 19:52:25: DEBUG: IV freed
2013-10-24 19:52:25: [ANDROID.IP] DEBUG: DPD R-U-There sent (0)
2013-10-24 19:52:25: [ANDROID.IP] DEBUG: rescheduling send_r_u (5).
INFO: DPD: remote (ISAKMP-SA spi=c0438f6223a8f3f3:72d24bf5c980aeb4) seems to be dead.

tcpdump on all connections from the Android client:

Code: 
listening on dc0, link-type EN10MB (Ethernet), capture size 65535 bytes
19:27:48.598556 IP ANDROID.IP.33340 > SERVER.IP.500: isakmp: phase 1 I ident
19:27:48.620432 IP SERVER.IP.500 > ANDROID.IP.33340: isakmp: phase 1 R ident
19:27:49.518825 IP ANDROID.IP.33340 > SERVER.IP.500: isakmp: phase 1 I ident
19:27:49.531577 IP SERVER.IP.500 > ANDROID.IP.33340: isakmp: phase 1 R ident
19:27:50.482412 IP ANDROID.IP.35605 > SERVER.IP.4500: NONESP-encap: isakmp: phase 1 I ident[E]
19:27:53.064023 IP ANDROID.IP.35605 > SERVER.IP.4500: NONESP-encap: isakmp: phase 1 I ident[E]
19:27:56.145664 IP ANDROID.IP.35605 > SERVER.IP.4500: NONESP-encap: isakmp: phase 1 I ident[E]
19:27:59.181806 IP ANDROID.IP.35605 > SERVER.IP.4500: NONESP-encap: isakmp: phase 1 I ident[E]
19:28:02.219749 IP ANDROID.IP.35605 > SERVER.IP.4500: NONESP-encap: isakmp: phase 1 I ident[E]
19:28:05.278630 IP ANDROID.IP.35605 > SERVER.IP.4500: NONESP-encap: isakmp: phase 1 I ident[E]
19:28:07.118834 IP ANDROID.IP.35605 > SERVER.IP.4500: isakmp-nat-keep-alive
19:28:08.919564 IP ANDROID.IP.35605 > SERVER.IP.4500: NONESP-encap: isakmp: phase 1 I ident[E]
19:28:11.199049 IP ANDROID.IP.35605 > SERVER.IP.4500: NONESP-encap: isakmp: phase 1 I ident[E]
19:28:14.139449 IP ANDROID.IP.35605 > SERVER.IP.4500: NONESP-encap: isakmp: phase 1 I ident[E]
19:28:17.159703 IP ANDROID.IP.35605 > SERVER.IP.4500: NONESP-encap: isakmp: phase 1 I ident[E]
19:28:20.119156 IP ANDROID.IP.59592 > SERVER.IP.1701:  l2tp:[TLS](0/0)Ns=0,Nr=0 *MSGTYPE(SCCRQ) *PROTO_VER(1.0) *HOST_NAME(anonymous) *FRAMING_CAP(AS) *ASSND_TUN_ID(59832) *RECV_WIN_SIZE(1)
19:28:20.199346 IP ANDROID.IP.59592 > SERVER.IP.1701:  l2tp:[TLS](0/0)Ns=0,Nr=0 *MSGTYPE(SCCRQ) *PROTO_VER(1.0) *HOST_NAME(anonymous) *FRAMING_CAP(AS) *ASSND_TUN_ID(59832) *RECV_WIN_SIZE(1)
19:28:20.199786 IP ANDROID.IP.59592 > SERVER.IP.1701:  l2tp:[TLS](0/0)Ns=1,Nr=0 *MSGTYPE(StopCCN) *ASSND_TUN_ID(59832) *RESULT_CODE(6)

mpd.log states only this:

Code: 
Oct 24 21:32:30 <daemon.info> walle mpd: process 4671 started, version 5.7 (root@walle.nora.whyers 07:58 15-Oct-2013)
Oct 24 21:32:30 <daemon.info> walle mpd: CONSOLE: listening on 127.0.0.1 5005
Oct 24 21:32:30 <daemon.info> walle mpd: web: listening on 172.16.5.3 5006
Oct 24 21:32:30 <daemon.info> walle mpd: L2TP: waiting for connection on 0.0.0.0 1701

Where should I dig?

Update:

dmesg -a:

Code: 
WARNING: pseudo-random number generator used for IPsec processing
key_update: NAT-T OAi/r present
key_add: NAT-T OAi/r present
 
You must log in or register to reply here.
Back
Top