Sending Access-Challenge instead of Access-Accept using MS-CHAPv2
Lasse Odden
lasse.odden at gmail.com
Mon Mar 13 12:31:18 CET 2017
This is the response I got from Cisco:
_________________
Thank you for the very detailed instructions. I was able to reproduce the
issue and I believe that freeradius is violating rfc2548 section 2.3.3:
2.3.3. MS-CHAP2-Success
Description
This Attribute contains a 42-octet authenticator response string.
This string MUST be included in the Message field of the MS-CHAP-
V2 Success packet sent from the NAS to the peer. This Attribute
is only used in Access-Accept packets.
In the packet capture I can see that the Access-Challenge contains
“MS-CHAP2-Success” attribute.
I have found a similar case and it looks like ASA is expecting
MS-CHAP2-Success along with proper Authenticator in the Access-Accept
message in order to properly validate the RADIUS exchange.
Unfortunately, I have no idea how to reconfigure the FreeRadius to conform
to this requirement.
_________________
This is my output:
Received Access-Request Id 164 from 172.28.0.18:63103 to 10.58.0.15:1812
length 241
User-Name = 'k00jlod'
NAS-Port = 27713536
Called-Station-Id = '82.147.36.212'
Calling-Station-Id = '77.106.182.238'
NAS-Port-Type = Virtual
Tunnel-Client-Endpoint:0 = '77.106.182.238'
MS-CHAP-Challenge = 0x8739b036b944ff2f3f7cba701f3e841b
MS-CHAP2-Response =
0x0000d6e0d53088952eadf04f9f0bcc07babb0000000000000000a4f05481ea47278d26d47d8f0f2ccd36235ece255201258f
NAS-IP-Address = 172.28.0.18
Cisco-AVPair = 'ip:source-ip=77.106.182.238'
ASA-TunnelGroupName = 'Two-factor'
ASA-ClientType = AnyConnect-Client-SSL-VPN
Mon Mar 13 12:27:10 2017 : Debug: (1) Received Access-Request packet from
host 172.28.0.18 port 63103, id=164, length=241
Mon Mar 13 12:27:10 2017 : Debug: (1) User-Name = 'k00jlod'
Mon Mar 13 12:27:10 2017 : Debug: (1) NAS-Port = 27713536
Mon Mar 13 12:27:10 2017 : Debug: (1) Called-Station-Id = '82.147.36.212'
Mon Mar 13 12:27:10 2017 : Debug: (1) Calling-Station-Id =
'77.106.182.238'
Mon Mar 13 12:27:10 2017 : Debug: (1) NAS-Port-Type = Virtual
Mon Mar 13 12:27:10 2017 : Debug: (1) Tunnel-Client-Endpoint:0 =
'77.106.182.238'
Mon Mar 13 12:27:10 2017 : Debug: (1) MS-CHAP-Challenge =
0x8739b036b944ff2f3f7cba701f3e841b
Mon Mar 13 12:27:10 2017 : Debug: (1) MS-CHAP2-Response =
0x0000d6e0d53088952eadf04f9f0bcc07babb0000000000000000a4f05481ea47278d26d47d8f0f2ccd36235ece255201258f
Mon Mar 13 12:27:10 2017 : Debug: (1) NAS-IP-Address = 172.28.0.18
Mon Mar 13 12:27:10 2017 : Debug: (1) Cisco-AVPair =
'ip:source-ip=77.106.182.238'
Mon Mar 13 12:27:10 2017 : Debug: (1) ASA-TunnelGroupName = 'Two-factor'
Mon Mar 13 12:27:10 2017 : Debug: (1) ASA-ClientType =
AnyConnect-Client-SSL-VPN
Mon Mar 13 12:27:10 2017 : Debug: (1) # Executing section authorize from
file /etc/raddb/sites-enabled/default
Mon Mar 13 12:27:10 2017 : Debug: (1) authorize {
Mon Mar 13 12:27:10 2017 : Debug: (1) filter_username filter_username {
Mon Mar 13 12:27:10 2017 : Debug: (1) if (!&User-Name)
Mon Mar 13 12:27:10 2017 : Debug: (1) if (!&User-Name) -> FALSE
Mon Mar 13 12:27:10 2017 : Debug: (1) if (&User-Name =~ / /)
Mon Mar 13 12:27:10 2017 : Debug: (1) if (&User-Name =~ / /) -> FALSE
Mon Mar 13 12:27:10 2017 : Debug: (1) if (&User-Name =~ /@.*@/ )
Mon Mar 13 12:27:10 2017 : Debug: (1) if (&User-Name =~ /@.*@/ ) ->
FALSE
Mon Mar 13 12:27:10 2017 : Debug: (1) if (&User-Name =~ /\\.\\./ )
Mon Mar 13 12:27:10 2017 : Debug: (1) if (&User-Name =~ /\\.\\./ ) ->
FALSE
Mon Mar 13 12:27:10 2017 : Debug: (1) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\\.(.+)$/))
Mon Mar 13 12:27:10 2017 : Debug: (1) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE
Mon Mar 13 12:27:10 2017 : Debug: (1) if (&User-Name =~ /\\.$/)
Mon Mar 13 12:27:10 2017 : Debug: (1) if (&User-Name =~ /\\.$/) ->
FALSE
Mon Mar 13 12:27:10 2017 : Debug: (1) if (&User-Name =~ /@\\./)
Mon Mar 13 12:27:10 2017 : Debug: (1) if (&User-Name =~ /@\\./) ->
FALSE
Mon Mar 13 12:27:10 2017 : Debug: (1) } # filter_username filter_username
= notfound
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [preprocess] = ok
Mon Mar 13 12:27:10 2017 : Debug: (1) if (State)
Mon Mar 13 12:27:10 2017 : Debug: (1) if (State) -> FALSE
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: calling chap
(rlm_chap) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: returned from
chap (rlm_chap) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [chap] = noop
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: calling mschap
(rlm_mschap) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : Found MS-CHAP attributes.
Setting 'Auth-Type = mschap'
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: returned from
mschap (rlm_mschap) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [mschap] = ok
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: calling digest
(rlm_digest) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: returned from
digest (rlm_digest) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [digest] = noop
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: calling suffix
(rlm_realm) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) suffix : Checking for suffix after
"@"
Mon Mar 13 12:27:10 2017 : Debug: (1) suffix : No '@' in User-Name =
"k00jlod", looking up realm NULL
Mon Mar 13 12:27:10 2017 : Debug: (1) suffix : No such realm "NULL"
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: returned from
suffix (rlm_realm) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [suffix] = noop
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: calling eap
(rlm_eap) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) eap : No EAP-Message, not doing EAP
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: returned from
eap (rlm_eap) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [eap] = noop
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: calling files
(rlm_files) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: returned from
files (rlm_files) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [files] = noop
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: calling
expiration (rlm_expiration) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: returned from
expiration (rlm_expiration) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [expiration] = noop
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: calling
logintime (rlm_logintime) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: returned from
logintime (rlm_logintime) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [logintime] = noop
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: calling pap
(rlm_pap) for request 1
Mon Mar 13 12:27:10 2017 : WARNING: (1) pap : No "known good" password
found for the user. Not setting Auth-Type
Mon Mar 13 12:27:10 2017 : WARNING: (1) pap : Authentication will fail
unless a "known good" password is available
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authorize]: returned from
pap (rlm_pap) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [pap] = noop
Mon Mar 13 12:27:10 2017 : Debug: (1) } # authorize = ok
Mon Mar 13 12:27:10 2017 : Debug: (1) Found Auth-Type = MSCHAP
Mon Mar 13 12:27:10 2017 : Debug: (1) # Executing group from file
/etc/raddb/sites-enabled/default
Mon Mar 13 12:27:10 2017 : Debug: (1) Auth-Type MS-CHAP {
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authenticate]: calling
mschap (rlm_mschap) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : Creating challenge hash
with username: k00jlod
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : Client is using MS-CHAPv2
Mon Mar 13 12:27:10 2017 : Debug: Executing: /usr/bin/ntlm_auth
--request-nt-key --username=%{mschap:User-Name}
--challenge=%{%{mschap:Challenge}:-00}
--nt-response=%{%{mschap:NT-Response}:-00} --domain=%{mschap:NT-Domain}:
Mon Mar 13 12:27:10 2017 : Debug: --username=%{mschap:User-Name}
Mon Mar 13 12:27:10 2017 : Debug: Parsed xlat tree:
Mon Mar 13 12:27:10 2017 : Debug: literal --> --username=
Mon Mar 13 12:27:10 2017 : Debug: xlat --> mschap
Mon Mar 13 12:27:10 2017 : Debug: {
Mon Mar 13 12:27:10 2017 : Debug: literal --> User-Name
Mon Mar 13 12:27:10 2017 : Debug: }
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : EXPAND
--username=%{mschap:User-Name}
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : --> --username=k00jlod
Mon Mar 13 12:27:10 2017 : Debug: --challenge=%{%{mschap:Challenge}:-00}
Mon Mar 13 12:27:10 2017 : Debug: Parsed xlat tree:
Mon Mar 13 12:27:10 2017 : Debug: literal --> --challenge=
Mon Mar 13 12:27:10 2017 : Debug: if {
Mon Mar 13 12:27:10 2017 : Debug: xlat --> mschap
Mon Mar 13 12:27:10 2017 : Debug: {
Mon Mar 13 12:27:10 2017 : Debug: literal --> Challenge
Mon Mar 13 12:27:10 2017 : Debug: }
Mon Mar 13 12:27:10 2017 : Debug: }
Mon Mar 13 12:27:10 2017 : Debug: else {
Mon Mar 13 12:27:10 2017 : Debug: literal --> 00
Mon Mar 13 12:27:10 2017 : Debug: }
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : Creating challenge hash
with username: k00jlod
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : EXPAND
--challenge=%{%{mschap:Challenge}:-00}
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : -->
--challenge=5be157fe7659ba10
Mon Mar 13 12:27:10 2017 : Debug: --nt-response=%{%{mschap:NT-Response}:-00}
Mon Mar 13 12:27:10 2017 : Debug: Parsed xlat tree:
Mon Mar 13 12:27:10 2017 : Debug: literal --> --nt-response=
Mon Mar 13 12:27:10 2017 : Debug: if {
Mon Mar 13 12:27:10 2017 : Debug: xlat --> mschap
Mon Mar 13 12:27:10 2017 : Debug: {
Mon Mar 13 12:27:10 2017 : Debug: literal --> NT-Response
Mon Mar 13 12:27:10 2017 : Debug: }
Mon Mar 13 12:27:10 2017 : Debug: }
Mon Mar 13 12:27:10 2017 : Debug: else {
Mon Mar 13 12:27:10 2017 : Debug: literal --> 00
Mon Mar 13 12:27:10 2017 : Debug: }
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : EXPAND
--nt-response=%{%{mschap:NT-Response}:-00}
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : -->
--nt-response=a4f05481ea47278d26d47d8f0f2ccd36235ece255201258f
Mon Mar 13 12:27:10 2017 : Debug: --domain=%{mschap:NT-Domain}
Mon Mar 13 12:27:10 2017 : Debug: Parsed xlat tree:
Mon Mar 13 12:27:10 2017 : Debug: literal --> --domain=
Mon Mar 13 12:27:10 2017 : Debug: xlat --> mschap
Mon Mar 13 12:27:10 2017 : Debug: {
Mon Mar 13 12:27:10 2017 : Debug: literal --> NT-Domain
Mon Mar 13 12:27:10 2017 : Debug: }
Mon Mar 13 12:27:10 2017 : ERROR: (1) mschap : No NT-Domain was found in
the User-Name
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : EXPAND
--domain=%{mschap:NT-Domain}
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : --> --domain=
Mon Mar 13 12:27:10 2017 : Debug: Program returned code (0) and output
'NT_KEY: 726FA77A206B0A0055EA8EC04BA5C7A8'
Mon Mar 13 12:27:10 2017 : Debug: (1) mschap : Adding MS-CHAPv2 MPPE keys
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authenticate]: returned
from mschap (rlm_mschap) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [mschap] = ok
Mon Mar 13 12:27:10 2017 : Debug: (1) challenge challenge {
Mon Mar 13 12:27:10 2017 : Debug: (1) update control {
Mon Mar 13 12:27:10 2017 : Debug: (1) &Response-Packet-Type =
Access-Challenge
Mon Mar 13 12:27:10 2017 : Debug: (1) } # update control = noop
Mon Mar 13 12:27:10 2017 : Debug: (1) update reply {
Mon Mar 13 12:27:10 2017 : Debug: (1) &Reply-Message = 'Tast inn din
engangskode.\n\nOm du ikke er registrert for sterk autentisering, kan dette
gjøres på nettsiden https://id.hedmark.org'
Mon Mar 13 12:27:10 2017 : Debug: (1) EXPAND %{randstr:nnnnnnnn}
Mon Mar 13 12:27:10 2017 : Debug: (1) --> 43934796
Mon Mar 13 12:27:10 2017 : Debug: (1) &State = 0x3433393334373936
Mon Mar 13 12:27:10 2017 : Debug: (1) } # update reply = noop
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authenticate]: calling
handled (rlm_always) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) modsingle[authenticate]: returned
from handled (rlm_always) for request 1
Mon Mar 13 12:27:10 2017 : Debug: (1) [handled] = handled
Mon Mar 13 12:27:10 2017 : Debug: (1) } # challenge challenge = handled
Mon Mar 13 12:27:10 2017 : Debug: (1) } # Auth-Type MS-CHAP = handled
Mon Mar 13 12:27:10 2017 : Debug: (1) Sending Access-Challenge packet to
host 172.28.0.18 port 63103, id=164, length=0
Mon Mar 13 12:27:10 2017 : Debug: (1) MS-CHAP2-Success =
0x00533d42333944423243394234453931304238454145414438444543314339353330333834343641313339
Mon Mar 13 12:27:10 2017 : Debug: (1) MS-MPPE-Recv-Key =
0x64f6fa51e30f7267fb3785e2061c501d
Mon Mar 13 12:27:10 2017 : Debug: (1) MS-MPPE-Send-Key =
0xefe9c04f5d551895ab42cef20b8767a2
Mon Mar 13 12:27:10 2017 : Debug: (1) MS-MPPE-Encryption-Policy =
Encryption-Allowed
Mon Mar 13 12:27:10 2017 : Debug: (1) MS-MPPE-Encryption-Types =
RC4-40or128-bit-Allowed
Mon Mar 13 12:27:10 2017 : Debug: (1) Reply-Message = 'Tast inn din
engangskode.\n\nOm du ikke er registrert for sterk autentisering, kan dette
gjøres på nettsiden https://id.hedmark.org'
Mon Mar 13 12:27:10 2017 : Debug: (1) State = 0x3433393334373936
Sending Access-Challenge Id 164 from 10.58.0.15:1812 to 172.28.0.18:63103
MS-CHAP2-Success =
0x00533d42333944423243394234453931304238454145414438444543314339353330333834343641313339
MS-MPPE-Recv-Key = 0x64f6fa51e30f7267fb3785e2061c501d
MS-MPPE-Send-Key = 0xefe9c04f5d551895ab42cef20b8767a2
MS-MPPE-Encryption-Policy = Encryption-Allowed
MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed
Reply-Message = 'Tast inn din engangskode.\n\nOm du ikke er
registrert for sterk autentisering, kan dette gjøres på nettsiden
https://id.hedmark.org'
State = 0x3433393334373936
Mon Mar 13 12:27:10 2017 : Debug: (1) Finished request
Mon Mar 13 12:27:10 2017 : Debug: Waking up in 0.2 seconds.
Mon Mar 13 12:27:11 2017 : Debug: Waking up in 4.7 seconds.
Mon Mar 13 12:27:15 2017 : Debug: (1) Cleaning up request packet ID 164
with timestamp +101
Mon Mar 13 12:27:15 2017 : Info: Ready to process requests
Received Access-Request Id 165 from 172.28.0.18:63103 to 10.58.0.15:1812
length 187
User-Name = 'k00jlod'
User-Password = '876274'
NAS-Port = 27713536
Called-Station-Id = '82.147.36.212'
Calling-Station-Id = '77.106.182.238'
NAS-Port-Type = Virtual
Tunnel-Client-Endpoint:0 = '77.106.182.238'
NAS-IP-Address = 172.28.0.18
State = 0x3433393334373936
Cisco-AVPair = 'ip:source-ip=77.106.182.238'
ASA-TunnelGroupName = 'Two-factor'
ASA-ClientType = AnyConnect-Client-SSL-VPN
Mon Mar 13 12:27:17 2017 : Debug: (2) Received Access-Request packet from
host 172.28.0.18 port 63103, id=165, length=187
Mon Mar 13 12:27:17 2017 : Debug: (2) User-Name = 'k00jlod'
Mon Mar 13 12:27:17 2017 : Debug: (2) User-Password = '876274'
Mon Mar 13 12:27:17 2017 : Debug: (2) NAS-Port = 27713536
Mon Mar 13 12:27:17 2017 : Debug: (2) Called-Station-Id = '82.147.36.212'
Mon Mar 13 12:27:17 2017 : Debug: (2) Calling-Station-Id =
'77.106.182.238'
Mon Mar 13 12:27:17 2017 : Debug: (2) NAS-Port-Type = Virtual
Mon Mar 13 12:27:17 2017 : Debug: (2) Tunnel-Client-Endpoint:0 =
'77.106.182.238'
Mon Mar 13 12:27:17 2017 : Debug: (2) NAS-IP-Address = 172.28.0.18
Mon Mar 13 12:27:17 2017 : Debug: (2) State = 0x3433393334373936
Mon Mar 13 12:27:17 2017 : Debug: (2) Cisco-AVPair =
'ip:source-ip=77.106.182.238'
Mon Mar 13 12:27:17 2017 : Debug: (2) ASA-TunnelGroupName = 'Two-factor'
Mon Mar 13 12:27:17 2017 : Debug: (2) ASA-ClientType =
AnyConnect-Client-SSL-VPN
Mon Mar 13 12:27:17 2017 : Debug: (2) # Executing section authorize from
file /etc/raddb/sites-enabled/default
Mon Mar 13 12:27:17 2017 : Debug: (2) authorize {
Mon Mar 13 12:27:17 2017 : Debug: (2) filter_username filter_username {
Mon Mar 13 12:27:17 2017 : Debug: (2) if (!&User-Name)
Mon Mar 13 12:27:17 2017 : Debug: (2) if (!&User-Name) -> FALSE
Mon Mar 13 12:27:17 2017 : Debug: (2) if (&User-Name =~ / /)
Mon Mar 13 12:27:17 2017 : Debug: (2) if (&User-Name =~ / /) -> FALSE
Mon Mar 13 12:27:17 2017 : Debug: (2) if (&User-Name =~ /@.*@/ )
Mon Mar 13 12:27:17 2017 : Debug: (2) if (&User-Name =~ /@.*@/ ) ->
FALSE
Mon Mar 13 12:27:17 2017 : Debug: (2) if (&User-Name =~ /\\.\\./ )
Mon Mar 13 12:27:17 2017 : Debug: (2) if (&User-Name =~ /\\.\\./ ) ->
FALSE
Mon Mar 13 12:27:17 2017 : Debug: (2) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\\.(.+)$/))
Mon Mar 13 12:27:17 2017 : Debug: (2) if ((&User-Name =~ /@/) &&
(&User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE
Mon Mar 13 12:27:17 2017 : Debug: (2) if (&User-Name =~ /\\.$/)
Mon Mar 13 12:27:17 2017 : Debug: (2) if (&User-Name =~ /\\.$/) ->
FALSE
Mon Mar 13 12:27:17 2017 : Debug: (2) if (&User-Name =~ /@\\./)
Mon Mar 13 12:27:17 2017 : Debug: (2) if (&User-Name =~ /@\\./) ->
FALSE
Mon Mar 13 12:27:17 2017 : Debug: (2) } # filter_username filter_username
= notfound
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) [preprocess] = ok
Mon Mar 13 12:27:17 2017 : Debug: (2) if (State)
Mon Mar 13 12:27:17 2017 : Debug: (2) if (State) -> TRUE
Mon Mar 13 12:27:17 2017 : Debug: (2) if (State) {
Mon Mar 13 12:27:17 2017 : Debug: (2) update control {
Mon Mar 13 12:27:17 2017 : Debug: (2) &Auth-Type := perl
Mon Mar 13 12:27:17 2017 : Debug: (2) } # update control = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) } # if (State) = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: calling chap
(rlm_chap) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: returned from
chap (rlm_chap) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) [chap] = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: calling mschap
(rlm_mschap) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: returned from
mschap (rlm_mschap) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) [mschap] = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: calling digest
(rlm_digest) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: returned from
digest (rlm_digest) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) [digest] = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: calling suffix
(rlm_realm) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) suffix : Checking for suffix after
"@"
Mon Mar 13 12:27:17 2017 : Debug: (2) suffix : No '@' in User-Name =
"k00jlod", looking up realm NULL
Mon Mar 13 12:27:17 2017 : Debug: (2) suffix : No such realm "NULL"
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: returned from
suffix (rlm_realm) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) [suffix] = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: calling eap
(rlm_eap) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) eap : No EAP-Message, not doing EAP
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: returned from
eap (rlm_eap) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) [eap] = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: calling files
(rlm_files) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: returned from
files (rlm_files) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) [files] = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: calling
expiration (rlm_expiration) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: returned from
expiration (rlm_expiration) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) [expiration] = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: calling
logintime (rlm_logintime) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: returned from
logintime (rlm_logintime) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) [logintime] = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: calling pap
(rlm_pap) for request 2
Mon Mar 13 12:27:17 2017 : WARNING: (2) pap : No "known good" password
found for the user. Not setting Auth-Type
Mon Mar 13 12:27:17 2017 : WARNING: (2) pap : Authentication will fail
unless a "known good" password is available
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authorize]: returned from
pap (rlm_pap) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) [pap] = noop
Mon Mar 13 12:27:17 2017 : Debug: (2) } # authorize = ok
Mon Mar 13 12:27:17 2017 : Debug: (2) Found Auth-Type = perl
Mon Mar 13 12:27:17 2017 : Debug: (2) # Executing group from file
/etc/raddb/sites-enabled/default
Mon Mar 13 12:27:17 2017 : Debug: (2) authenticate {
Mon Mar 13 12:27:17 2017 : Debug: (2) modsingle[authenticate]: calling
perl (rlm_perl) for request 2
Mon Mar 13 12:27:17 2017 : Debug: (2) perl : $RAD_REQUEST{'User-Name'} =
&request:User-Name -> 'k00jlod'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl :
$RAD_REQUEST{'User-Password'} = &request:User-Password -> '876274'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl :
$RAD_REQUEST{'NAS-IP-Address'} = &request:NAS-IP-Address -> '172.28.0.18'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl : $RAD_REQUEST{'NAS-Port'} =
&request:NAS-Port -> '27713536'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl : $RAD_REQUEST{'State'} =
&request:State -> '0x3433393334373936'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl :
$RAD_REQUEST{'Called-Station-Id'} = &request:Called-Station-Id ->
'82.147.36.212'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl :
$RAD_REQUEST{'Calling-Station-Id'} = &request:Calling-Station-Id ->
'77.106.182.238'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl :
$RAD_REQUEST{'NAS-Port-Type'} = &request:NAS-Port-Type -> 'Virtual'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl :
$RAD_REQUEST{'Tunnel-Client-Endpoint'} = &request:Tunnel-Client-Endpoint ->
'77.106.182.238'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl :
$RAD_REQUEST{'Event-Timestamp'} = &request:Event-Timestamp -> 'Mar 13 2017
12:27:17 CET'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl : $RAD_REQUEST{'Cisco-AVPair'}
= &request:Cisco-AVPair -> 'ip:source-ip=77.106.182.238'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl :
$RAD_REQUEST{'ASA-TunnelGroupName'} = &request:ASA-TunnelGroupName ->
'Two-factor'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl :
$RAD_REQUEST{'ASA-ClientType'} = &request:ASA-ClientType ->
'AnyConnect-Client-SSL-VPN'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl : $RAD_CHECK{'Auth-Type'} =
&control:Auth-Type -> 'perl'
Mon Mar 13 12:27:17 2017 : Debug: (2) perl : $RAD_CONFIG{'Auth-Type'} =
&control:Auth-Type -> 'perl'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:NAS-Port-Type =
$RAD_REQUEST{'NAS-Port-Type'} -> 'Virtual'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:ASA-ClientType =
$RAD_REQUEST{'ASA-ClientType'} -> 'AnyConnect-Client-SSL-VPN'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:ASA-TunnelGroupName
= $RAD_REQUEST{'ASA-TunnelGroupName'} -> 'Two-factor'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:Calling-Station-Id =
$RAD_REQUEST{'Calling-Station-Id'} -> '77.106.182.238'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:Called-Station-Id =
$RAD_REQUEST{'Called-Station-Id'} -> '82.147.36.212'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:State =
$RAD_REQUEST{'State'} -> '0x3433393334373936'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:Cisco-AVPair =
$RAD_REQUEST{'Cisco-AVPair'} -> 'ip:source-ip=77.106.182.238'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:User-Name =
$RAD_REQUEST{'User-Name'} -> 'k00jlod'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:Event-Timestamp =
$RAD_REQUEST{'Event-Timestamp'} -> 'Mar 13 2017 12:27:17 CET'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:User-Password =
$RAD_REQUEST{'User-Password'} -> '876274'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl :
&request:Tunnel-Client-Endpoint:0 =
$RAD_REQUEST{'Tunnel-Client-Endpoint:0'} -> '77.106.182.238'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:NAS-IP-Address =
$RAD_REQUEST{'NAS-IP-Address'} -> '172.28.0.18'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &request:NAS-Port =
$RAD_REQUEST{'NAS-Port'} -> '27713536'
Mon Mar 13 12:27:22 2017 : Debug: (2) perl : &control:Auth-Type =
$RAD_CHECK{'Auth-Type'} -> 'perl'
Mon Mar 13 12:27:22 2017 : Debug: (2) modsingle[authenticate]: returned
from perl (rlm_perl) for request 2
Mon Mar 13 12:27:22 2017 : Debug: (2) [perl] = ok
Mon Mar 13 12:27:22 2017 : Debug: (2) } # authenticate = ok
Mon Mar 13 12:27:22 2017 : Debug: (2) # Executing section post-auth from
file /etc/raddb/sites-enabled/default
Mon Mar 13 12:27:22 2017 : Debug: (2) post-auth {
Mon Mar 13 12:27:22 2017 : Debug: (2) modsingle[post-auth]: calling exec
(rlm_exec) for request 2
Mon Mar 13 12:27:22 2017 : Debug: (2) modsingle[post-auth]: returned from
exec (rlm_exec) for request 2
Mon Mar 13 12:27:22 2017 : Debug: (2) [exec] = noop
Mon Mar 13 12:27:22 2017 : Debug: (2) remove_reply_message_if_eap
remove_reply_message_if_eap {
Mon Mar 13 12:27:22 2017 : Debug: (2) if (&reply:EAP-Message &&
&reply:Reply-Message)
Mon Mar 13 12:27:22 2017 : Debug: (2) if (&reply:EAP-Message &&
&reply:Reply-Message) -> FALSE
Mon Mar 13 12:27:22 2017 : Debug: (2) else else {
Mon Mar 13 12:27:22 2017 : Debug: (2) modsingle[post-auth]: calling noop
(rlm_always) for request 2
Mon Mar 13 12:27:22 2017 : Debug: (2) modsingle[post-auth]: returned from
noop (rlm_always) for request 2
Mon Mar 13 12:27:22 2017 : Debug: (2) [noop] = noop
Mon Mar 13 12:27:22 2017 : Debug: (2) } # else else = noop
Mon Mar 13 12:27:22 2017 : Debug: (2) } # remove_reply_message_if_eap
remove_reply_message_if_eap = noop
Mon Mar 13 12:27:22 2017 : Debug: (2) } # post-auth = noop
Mon Mar 13 12:27:22 2017 : Debug: (2) Sending Access-Accept packet to host
172.28.0.18 port 63103, id=165, length=0
Sending Access-Accept Id 165 from 10.58.0.15:1812 to 172.28.0.18:63103
Mon Mar 13 12:27:22 2017 : Debug: (2) Finished request
Mon Mar 13 12:27:22 2017 : Debug: Waking up in 4.9 seconds.
Do you have any suggestion or answer to Cisco?
Best regards,
Lasse Odden
On Mon, Mar 6, 2017 at 2:54 PM, Alan DeKok <aland at deployingradius.com>
wrote:
> On Mar 6, 2017, at 7:55 AM, Lasse Odden <lasse.odden at gmail.com> wrote:
> > I've set up a two-factor athentication against our Cisco AnyConnect VPN
> > with access-challenge (this works when I use PAP between Cisco and
> > FreeRADIUS).
>
> That's a common scenario.
>
> > But with the username and password being sent between the Cisco and the
> > FreeRADIUS-server in cleartext I enabled "Password management" on the
> Cisco
> > ASA, so it sends the password with MS-CHAPv2.
>
> That's less common.
>
> > The Cisco ASA recieves the Challenge and promts for and challenge. When I
> > type in the correct challenge the FreeRADIUS sends an Access-Accept, but
> > the Cisco ASA won't allow it.
>
> Then the Cisco is broken.
>
> > My question is if this is allowed by the standard or is it a bug on
> Cisco's
> > side?
>
> It's definitely allowed by the standard. But probably a situation where
> the Cisco people never thought about it, and never tried it.
>
> Alan DeKok.
>
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/
> list/users.html
More information about the Freeradius-Users
mailing list