2 Factor Authentication

Dudás Péter peter.pdudas at gmail.com
Thu Jan 5 16:00:59 CET 2017


Dear Stefan!

This is the log of the firewall for an unsuccessful connection:

2017-01-05 15:35:23 accel-pppd msg=:: recv [L2TP tid=0 sid=0 Ns=0 Nr=0
<Message-Type Start-Ctrl-Conn-Request> <Protocol-Version 256>
<Framing-Capabilities 3> <Host-Name Peters-iPad> <Assigned-Tunnel-ID 34>
<Recv-Window-Size 4>]   Debug
2017-01-05 15:35:23 accel-pppd msg=:: send [L2TP tid=34 sid=0 Ns=0 Nr=1
<Message-Type Start-Ctrl-Conn-Reply> <Protocol-Version 256> <Host-Name
POW1> <Framing-Capabilities 3> <Assigned-Tunnel-ID 1> <Vendor-Name
accel-ppp>]   Debug
2017-01-05 15:35:23 accel-pppd msg=:: recv [L2TP tid=1 sid=0 Ns=1 Nr=1
<Message-Type Start-Ctrl-Conn-Connected>]   Debug
2017-01-05 15:35:23 accel-pppd msg=:: recv [L2TP tid=1 sid=0 Ns=2 Nr=1
<Message-Type Incoming-Call-Request> <Assigned-Session-ID 332>
<Call-Serial-Number 1>]   Debug
2017-01-05 15:35:23 accel-pppd msg=:: send [L2TP tid=34 sid=332 Ns=1 Nr=3
<Message-Type Incoming-Call-Reply> <Assigned-Session-ID 1>]   Debug
2017-01-05 15:35:23 accel-pppd msg=:: recv [L2TP tid=1 sid=1 Ns=3 Nr=2
<Message-Type Incoming-Call-Connected> <TX-Speed 1000000> <Framing-Type 3>]
  Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: connect: ppp0 <--> l2tp(
89.212.168.xyz)   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: lcp_layer_init   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: auth_layer_init   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: ccp_layer_init   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: ipcp_layer_init   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: ipv6cp_layer_init   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: ppp established   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: lcp_layer_start   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: send [LCP ConfReq id=1 <auth
MSCHAP-v2> <magic 2df6d648> <mru 1400>]   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: send [L2TP tid=34 sid=0 Ns=2
Nr=4]   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: recv [LCP ConfReq id=1 < 2 6 0 0
0 0 > <magic 57044e1e> <pcomp> <accomp>]   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: send [LCP ConfRej id=1  < 2 6 0 0
0 0 > <pcomp> <accomp>]   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: recv [LCP ConfAck id=1 <auth
MSCHAP-v2> <magic 2df6d648> <mru 1400>]   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: recv [LCP ConfReq id=2 <magic
57044e1e>]   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: send [LCP ConfAck id=2 ]   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: lcp_layer_started   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: auth_layer_start   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: send [MSCHAP-v2 Challenge id=1
<9db289b1154a96a74592f6278d5fbbc>]   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: recv [LCP EchoReq id=0 <magic
57044e1e>]   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: send [LCP EchoRep id=0 <magic
48d6f62d>]   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: recv [MSCHAP-v2 Response id=1
<9864eb6874e71568292ed3764e322a8>,
<62eb71aa08cf141c9d171c92ae423c08d1822fdcb47f>, F=0, name="Peter Dudas"]
Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: tpas: id:1 flags:0x0
reserved:0x33800a93   Debug
2017-01-05 15:35:23 accel-pppd msg=ppp0:: tpas: auth_hand started (pid
19780)   Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:: tpas: auth_hnd finished (0)
Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:: tpas: result:OKAY
S=D00BCA794534EC5AB5EB766E9AFD0B681CEA998E,A=a55b40eb94e2e1b7374b96d443b97397,B=5bc402515bbe524b8d983712821dc3bf
  Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: send [MSCHAP-v2
Success id=1 "S=D00BCA794534EC5AB5EB766E9AFD0B681CEA998E M=Authentication
succeeded"]   Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: recv [MSCHAP-v2
Response id=1 <9864eb6874e71568292ed3764e322a8>,
<62eb71aa08cf141c9d171c92ae423c08d1822fdcb47f>, F=0, name="Peter Dudas"]
Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: tpas: id:1 flags:0x0
reserved:0x33800a93   Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: tpas: auth_hand
started (pid 19782)   Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: tpas: auth_hnd
finished (0)   Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: tpas: result:OKAY
Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: send [MSCHAP-v2
Failure id=1 "9db289b1154a96a745920f6278d5fbbc M=Access denied"]   Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: ppp_terminate   Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: lcp_layer_finish
Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: send [LCP TermReq
id=3]   Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: auth_layer_finish
Debug
2017-01-05 15:35:27 accel-pppd msg=ppp0:Peter Dudas: auth_layer_finished
Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: IPCP: discarding
packet   Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: IPV6CP: discarding
packet   Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: recv [LCP TermAck
id=3]   Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: lcp_layer_finished
Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: lcp_layer_free   Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: auth_layer_free   Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: ccp_layer_free   Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: ipcp_layer_free   Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: ipv6cp_layer_free
Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: ppp destablished
Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: l2tp: ppp finished
Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: l2tp: terminate (0, 0)
  Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:Peter Dudas: send [L2TP tid=34
sid=0 Ns=2 Nr=4 <Message-Type Stop-Ctrl-Conn-Notify> <Assigned-Tunnel-ID 1>
<Result-Code>]   Debug
2017-01-05 15:35:28 accel-pppd msg=ppp0:: disconnected   Debug

And this is the successful:

2017-01-05 15:34:26 accel-pppd msg=:: recv [L2TP tid=0 sid=0 Ns=0 Nr=0
<Message-Type Start-Ctrl-Conn-Request> <Protocol-Version 256>
<Framing-Capabilities 3> <Host-Name Peters-iPad> <Assigned-Tunnel-ID 33>
<Recv-Window-Size 4>]   Debug
2017-01-05 15:34:26 accel-pppd msg=:: send [L2TP tid=33 sid=0 Ns=0 Nr=1
<Message-Type Start-Ctrl-Conn-Reply> <Protocol-Version 256> <Host-Name
POW1> <Framing-Capabilities 3> <Assigned-Tunnel-ID 1> <Vendor-Name
accel-ppp>]   Debug
2017-01-05 15:34:26 accel-pppd msg=:: recv [L2TP tid=1 sid=0 Ns=1 Nr=1
<Message-Type Start-Ctrl-Conn-Connected>]   Debug
2017-01-05 15:34:26 accel-pppd msg=:: recv [L2TP tid=1 sid=0 Ns=2 Nr=1
<Message-Type Incoming-Call-Request> <Assigned-Session-ID 329>
<Call-Serial-Number 1>]   Debug
2017-01-05 15:34:26 accel-pppd msg=:: send [L2TP tid=33 sid=329 Ns=1 Nr=3
<Message-Type Incoming-Call-Reply> <Assigned-Session-ID 1>]   Debug
2017-01-05 15:34:26 accel-pppd msg=:: recv [L2TP tid=1 sid=1 Ns=3 Nr=2
<Message-Type Incoming-Call-Connected> <TX-Speed 1000000> <Framing-Type 3>]
  Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: connect: ppp0 <--> l2tp(
89.212.168.xyz)   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: lcp_layer_init   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: auth_layer_init   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: ccp_layer_init   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: ipcp_layer_init   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: ipv6cp_layer_init   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: ppp established   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: lcp_layer_start   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: send [LCP ConfReq id=1 <auth
MSCHAP-v2> <magic 68ebc550> <mru 1400>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: send [L2TP tid=33 sid=0 Ns=2
Nr=4]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: recv [LCP ConfReq id=1 < 2 6 0 0
0 0 > <magic 568bf110> <pcomp> <accomp>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: send [LCP ConfRej id=1  < 2 6 0 0
0 0 > <pcomp> <accomp>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: recv [LCP ConfAck id=1 <auth
MSCHAP-v2> <magic 68ebc550> <mru 1400>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: recv [LCP ConfReq id=2 <magic
568bf110>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: send [LCP ConfAck id=2 ]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: lcp_layer_started   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: auth_layer_start   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: send [MSCHAP-v2 Challenge id=1
<b8cbbfa020ddad1e20bc4060c7bccfbf>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: recv [LCP EchoReq id=0 <magic
568bf110>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: send [LCP EchoRep id=0 <magic
50c5eb68>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: recv [MSCHAP-v2 Response id=1
<f1b3381d9a30e73a1dbd579844e575d2>,
<7371de3c435d275975f17eae3ec9d5755a86207626f6>, F=0, name="Peter Dudas"]
Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: tpas: id:1 flags:0x0
reserved:0x33800a93   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: tpas: auth_hand started (pid
19749)   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: tpas: auth_hnd finished (0)
Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:: tpas: result:OKAY
S=A540183EFBE609F94EAD79D80707C8D5ADC5C03A,A=79ebb8ec3143d8deb34d66dbbd900d88,B=1695340260afd1034cc9289f4535c415
  Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: send [MSCHAP-v2
Success id=1 "S=A540183EFBE609F94EAD79D80707C8D5ADC5C03A M=Authentication
succeeded"]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: auth_layer_started
Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: ccp_layer_start   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: ipcp_layer_start
Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: send [IPCP ConfReq
id=1 <addr 10.148.76.36>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: ipv6cp_layer_start
Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: Peter Dudas:
authentication succeeded   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: recv [IPCP ConfReq
id=1 <addr 0.0.0.0> <dns1 0.0.0.0> <dns2 0.0.0.0>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: send [IPCP ConfNak
id=1 <addr 10.148.76.45> <dns1 10.101.168.3> <dns2 10.101.168.35>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: IPV6CP: discarding
packet   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: send [LCP ProtoRej
id=3 <8057>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: recv [IPCP ConfAck
id=1 <addr 10.148.76.36>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: recv [IPCP ConfReq
id=2 <addr 10.148.76.45> <dns1 10.101.168.3> <dns2 10.101.168.35>]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: send [IPCP ConfAck
id=2]   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: ipcp_layer_started
Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: l2tp: ppp started
Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: tpas: ip-up started
(pid 19751)   Debug
2017-01-05 15:34:26 accel-pppd msg=ppp0:Peter Dudas: tpas: ip-up finished
(0)   Debug

So it looks like a failed MsChapv2 authentication - which does not makes
sense...
It is the same mschap module with ntlm_auth.
Does the challenge/response packets have a timeout?

Peter Dudas

On 5 January 2017 at 14:14, Stefan Paetow <Stefan.Paetow at jisc.ac.uk> wrote:

> >I'm not aware of any timing limitations (as with the SSLVPN I can even
> >wait
> >for 30s using the same 2nd authentication as for L2TP) - the whole chain
> >(firewall-Nps-Freeradius) has minimum 30s timeout configured.
>
> Ok... If 30 seconds is not enough, that is a bit of a concern.
>
> >With 'Sleep 3' it is still connected successfully - anything above 3
> >seconds just makes the L2TP VPN connection unsuccessful.
> >Checked in the firewall - timeout is 90s.
>
> You might want to check what the complete end-to-end timing is...
>
> Stefan Paetow
> Moonshot Industry & Research Liaison Coordinator
>
> t: +44 (0)1235 822 125
> gpg: 0x3FCE5142
> xmpp: stefanp at jabber.dev.ja.net
> skype: stefan.paetow.janet
>
> jisc.ac.uk
>
> Jisc is a registered charity (number 1149740) and a company limited by
> guarantee which is registered in England under Company No. 5747339, VAT
> No. GB 197 0632 86. Jisc¹s registered office is: One Castlepark, Tower
> Hill, Bristol, BS2 0JA. T 0203 697 5800.
>
>
>
>
> >
>
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/
> list/users.html
>


More information about the Freeradius-Users mailing list