Google authenticator : Access-Reject

servernemesis at tutanota.com servernemesis at tutanota.com
Tue Apr 24 15:15:20 CEST 2018


Thanks for your help, here is the full debug :

Tue Apr 24 15:06:13 2018 : Debug: Threads: total/active/spare threads = 5/0/5
Tue Apr 24 15:06:13 2018 : Debug: Waking up in 0.3 seconds.
Tue Apr 24 15:06:13 2018 : Debug: Thread 5 got semaphore
Tue Apr 24 15:06:13 2018 : Debug: Thread 5 handling request 0, (1 handled so far)
Tue Apr 24 15:06:13 2018 : Debug: (0) Received Access-Request Id 86 from 127.0.0.1:47786 to 127.0.0.1:1812 length 92
Tue Apr 24 15:06:13 2018 : Debug: (0)   User-Name = "user at mydomain.com <mailto:user at mydomain.com>"
Tue Apr 24 15:06:13 2018 : Debug: (0)   User-Password = "password123456"
Tue Apr 24 15:06:13 2018 : Debug: (0)   NAS-IP-Address = 127.0.1.1
Tue Apr 24 15:06:13 2018 : Debug: (0)   NAS-Port = 18120
Tue Apr 24 15:06:13 2018 : Debug: (0)   Message-Authenticator = 0x5f5b5b060935a0141122f9c08e0c4aa6
Tue Apr 24 15:06:13 2018 : Debug: (0) session-state: No State attribute
Tue Apr 24 15:06:13 2018 : Debug: (0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default
Tue Apr 24 15:06:13 2018 : Debug: (0)   authorize {
Tue Apr 24 15:06:13 2018 : Debug: (0)     policy filter_username {
Tue Apr 24 15:06:13 2018 : Debug: (0)       if (&User-Name) {
Tue Apr 24 15:06:13 2018 : Debug: (0)       if (&User-Name)  -> TRUE
Tue Apr 24 15:06:13 2018 : Debug: (0)       if (&User-Name)  {
Tue Apr 24 15:06:13 2018 : Debug: (0)         if (&User-Name =~ / /) {
Tue Apr 24 15:06:13 2018 : Debug: (0)         if (&User-Name =~ / /)  -> FALSE
Tue Apr 24 15:06:13 2018 : Debug: (0)         if (&User-Name =~ /@[^@]*@/ ) {
Tue Apr 24 15:06:13 2018 : Debug: (0)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
Tue Apr 24 15:06:13 2018 : Debug: (0)         if (&User-Name =~ /\.\./ ) {
Tue Apr 24 15:06:13 2018 : Debug: (0)         if (&User-Name =~ /\.\./ )  -> FALSE
Tue Apr 24 15:06:13 2018 : Debug: (0)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
Tue Apr 24 15:06:13 2018 : Debug: (0)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
Tue Apr 24 15:06:13 2018 : Debug: (0)         if (&User-Name =~ /\.$/)  {
Tue Apr 24 15:06:13 2018 : Debug: (0)         if (&User-Name =~ /\.$/)   -> FALSE
Tue Apr 24 15:06:13 2018 : Debug: (0)         if (&User-Name =~ /@\./)  {
Tue Apr 24 15:06:13 2018 : Debug: (0)         if (&User-Name =~ /@\./)   -> FALSE
Tue Apr 24 15:06:13 2018 : Debug: (0)       } # if (&User-Name)  = notfound
Tue Apr 24 15:06:13 2018 : Debug: (0)     } # policy filter_username = notfound
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: calling preprocess (rlm_preprocess)
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: returned from preprocess (rlm_preprocess)
Tue Apr 24 15:06:13 2018 : Debug: (0)     [preprocess] = ok
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: calling chap (rlm_chap)
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: returned from chap (rlm_chap)
Tue Apr 24 15:06:13 2018 : Debug: (0)     [chap] = noop
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: calling mschap (rlm_mschap)
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: returned from mschap (rlm_mschap)
Tue Apr 24 15:06:13 2018 : Debug: (0)     [mschap] = noop
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: calling digest (rlm_digest)
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: returned from digest (rlm_digest)
Tue Apr 24 15:06:13 2018 : Debug: (0)     [digest] = noop
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: calling suffix (rlm_realm)
Tue Apr 24 15:06:13 2018 : Debug: (0) suffix: Checking for suffix after "@"
Tue Apr 24 15:06:13 2018 : Debug: (0) suffix: Looking up realm "mydomain.com" for User-Name = "user at mydomain.com <mailto:user at mydomain.com>"
Tue Apr 24 15:06:13 2018 : Debug: (0) suffix: No such realm "mydomain.com"
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: returned from suffix (rlm_realm)
Tue Apr 24 15:06:13 2018 : Debug: (0)     [suffix] = noop
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: calling eap (rlm_eap)
Tue Apr 24 15:06:13 2018 : Debug: (0) eap: No EAP-Message, not doing EAP
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: returned from eap (rlm_eap)
Tue Apr 24 15:06:13 2018 : Debug: (0)     [eap] = noop
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: calling files (rlm_files)
Tue Apr 24 15:06:13 2018 : Debug: (0) files: users: Matched entry DEFAULT at line 221
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: returned from files (rlm_files)
Tue Apr 24 15:06:13 2018 : Debug: (0)     [files] = ok
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: calling expiration (rlm_expiration)
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: returned from expiration (rlm_expiration)
Tue Apr 24 15:06:13 2018 : Debug: (0)     [expiration] = noop
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: calling logintime (rlm_logintime)
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: returned from logintime (rlm_logintime)
Tue Apr 24 15:06:13 2018 : Debug: (0)     [logintime] = noop
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: calling pap (rlm_pap)
Tue Apr 24 15:06:13 2018 : WARNING: (0) pap: No "known good" password found for the user.  Not setting Auth-Type
Tue Apr 24 15:06:13 2018 : WARNING: (0) pap: Authentication will fail unless a "known good" password is available
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authorize]: returned from pap (rlm_pap)
Tue Apr 24 15:06:13 2018 : Debug: (0)     [pap] = noop
Tue Apr 24 15:06:13 2018 : Debug: (0)   } # authorize = ok
Tue Apr 24 15:06:13 2018 : Debug: (0) Found Auth-Type = pam
Tue Apr 24 15:06:13 2018 : Debug: (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
Tue Apr 24 15:06:13 2018 : Debug: (0)   authenticate {
Tue Apr 24 15:06:13 2018 : Debug: (0)     modsingle[authenticate]: calling pam (rlm_pam)
Tue Apr 24 15:06:13 2018 : Debug: (0) pam: Using pamauth string "radiusd" for pam.conf lookup
Tue Apr 24 15:06:13 2018 : Debug: Waking up in 0.3 seconds.
Tue Apr 24 15:06:13 2018 : Debug: Waking up in 0.2 seconds.
Tue Apr 24 15:06:13 2018 : Debug: Waking up in 0.4 seconds.
Tue Apr 24 15:06:14 2018 : Debug: Waking up in 0.7 seconds.
Tue Apr 24 15:06:14 2018 : Debug: Waking up in 1.1 seconds.
Tue Apr 24 15:06:15 2018 : ERROR: (0) pam: pam_authenticate failed: Authentication failure
Tue Apr 24 15:06:15 2018 : Debug: (0)     modsingle[authenticate]: returned from pam (rlm_pam)
Tue Apr 24 15:06:15 2018 : Debug: (0)     [pam] = reject
Tue Apr 24 15:06:15 2018 : Debug: (0)   } # authenticate = reject
Tue Apr 24 15:06:15 2018 : Debug: (0) Failed to authenticate the user
Tue Apr 24 15:06:15 2018 : Debug: (0) Using Post-Auth-Type Reject
Tue Apr 24 15:06:15 2018 : Debug: (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
Tue Apr 24 15:06:15 2018 : Debug: (0)   Post-Auth-Type REJECT {
Tue Apr 24 15:06:15 2018 : Debug: (0)     modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter)
Tue Apr 24 15:06:15 2018 : Debug: %{User-Name}
Tue Apr 24 15:06:15 2018 : Debug: Parsed xlat tree:
Tue Apr 24 15:06:15 2018 : Debug: attribute --> User-Name
Tue Apr 24 15:06:15 2018 : Debug: (0) attr_filter.access_reject: EXPAND %{User-Name}
Tue Apr 24 15:06:15 2018 : Debug: (0) attr_filter.access_reject:    --> user at mydomain.com <mailto:user at mydomain.com>
Tue Apr 24 15:06:15 2018 : Debug: (0) attr_filter.access_reject: Matched entry DEFAULT at line 11
Tue Apr 24 15:06:15 2018 : Debug: (0)     modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter)
Tue Apr 24 15:06:15 2018 : Debug: (0)     [attr_filter.access_reject] = updated
Tue Apr 24 15:06:15 2018 : Debug: (0)     modsingle[post-auth]: calling eap (rlm_eap)
Tue Apr 24 15:06:15 2018 : Debug: (0) eap: Request didn't contain an EAP-Message, not inserting EAP-Failure
Tue Apr 24 15:06:15 2018 : Debug: (0)     modsingle[post-auth]: returned from eap (rlm_eap)
Tue Apr 24 15:06:15 2018 : Debug: (0)     [eap] = noop
Tue Apr 24 15:06:15 2018 : Debug: (0)     policy remove_reply_message_if_eap {
Tue Apr 24 15:06:15 2018 : Debug: (0)       if (&reply:EAP-Message && &reply:Reply-Message) {
Tue Apr 24 15:06:15 2018 : Debug: (0)       if (&reply:EAP-Message && &reply:Reply-Message)  -> FALSE
Tue Apr 24 15:06:15 2018 : Debug: (0)       else {
Tue Apr 24 15:06:15 2018 : Debug: (0)         modsingle[post-auth]: calling noop (rlm_always)
Tue Apr 24 15:06:15 2018 : Debug: (0)         modsingle[post-auth]: returned from noop (rlm_always)
Tue Apr 24 15:06:15 2018 : Debug: (0)         [noop] = noop
Tue Apr 24 15:06:15 2018 : Debug: (0)       } # else = noop
Tue Apr 24 15:06:15 2018 : Debug: (0)     } # policy remove_reply_message_if_eap = noop
Tue Apr 24 15:06:15 2018 : Debug: (0)   } # Post-Auth-Type REJECT = updated
Tue Apr 24 15:06:15 2018 : Debug: (0) Delaying response for 1.000000 seconds
Tue Apr 24 15:06:15 2018 : Debug: Thread 5 waiting to be assigned a request
Tue Apr 24 15:06:16 2018 : Debug: Waking up in 0.2 seconds.
Tue Apr 24 15:06:16 2018 : Debug: (0) Sending delayed response
Tue Apr 24 15:06:16 2018 : Debug: (0) Sent Access-Reject Id 86 from 127.0.0.1:1812 to 127.0.0.1:47786 length 20
Tue Apr 24 15:06:16 2018 : Debug: Waking up in 3.9 seconds.
Tue Apr 24 15:06:20 2018 : Debug: (0) Cleaning up request packet ID 86 with timestamp +29
Tue Apr 24 15:06:20 2018 : Info: Ready to process requests




24. Avr 2018 12:44 de eero.volotinen at iki.fi <mailto:eero.volotinen at iki.fi>:


> well. check out all logs and run freeradius in debug mode -XXX (if I
> remember switch correctly)
>
> Eero
>
> ti 24. huhtik. 2018 klo 12.34 <> servernemesis at tutanota.com <mailto:servernemesis at tutanota.com>> > kirjoitti:
>
>> I log with the fqdn (use_fully_qualified_names true in sssd)
>> But I tried without and same problem.
>>
>> >
>> Try radtest without @doman part, as It is not part of usernameEero
>> 24. Avr 2018 12:08 de >> servernemesis at tutanota.com <mailto:servernemesis at tutanota.com>>>  <mailto:
>> servernemesis at tutanota.com <mailto:servernemesis at tutanota.com>>> >:
>>
>>
>> > PS :
>> >  With this line in /etc/pam.d/sshd :
>> > "auth required  /usr/local/lib/security/pam_google_authenticator.so"
>> > I'm able to do ssh login with my google auth code.
>> >
>> >
>> > 24. Avr 2018 11:48 de > >> servernemesis at tutanota.com <mailto:servernemesis at tutanota.com>>>  <mailto:
>> servernemesis at tutanota.com <mailto:servernemesis at tutanota.com>>> >> :
>> >
>> >
>> >>
>> >> Hello,
>> >>
>> >> I followed this tutorial (>>
>> https://www.techdrabble.com/citrix/14-2factor-with-google-authenticator-and-netscaler <https://www.techdrabble.com/citrix/14-2factor-with-google-authenticator-and-netscaler>
>> <
>> https://www.techdrabble.com/citrix/14-2factor-with-google-authenticator-and-netscaler <https://www.techdrabble.com/citrix/14-2factor-with-google-authenticator-and-netscaler>>> >>>
>> ) and managed to get it running on Debian 9 with FR 3.0.12 thanks to the
>> help here. But I have another issue : when I try to authenticate with
>> password + googleauth code, I got rejected.
>> >> I'm able to log on the FR server with domain credentials without
>> problem. The google auth code gets generated without issue either.
>> >>
>> >> Radtest:
>> >> radtest >> >> user at mydomain.com <mailto:user at mydomain.com>>>  <>> mailto:user at mydomain.com <mailto:mailto:user at mydomain.com>>> >>>
>> password123456 localhost 18120 testing123
>> >> Sent Access-Request Id 226 from 0.0.0.0:38763 to 127.0.0.1:1812 length
>> 92
>> >>         User-Name = ">> >> user at mydomain.com <mailto:user at mydomain.com>>>  <>> mailto:user at mydomain.com <mailto:mailto:user at mydomain.com>>> >>>
>> "
>> >>         User-Password = "password123456"
>> >>         NAS-IP-Address = 127.0.1.1
>> >>         NAS-Port = 18120
>> >>         Message-Authenticator = 0x00
>> >>         Cleartext-Password = "password123456"
>> >> Received Access-Reject Id 226 from 127.0.0.1:1812 to 0.0.0.0:0 length
>> 20
>> >> (0) -: Expected Access-Accept got Access-Reject
>> >>
>> >>
>> >> Log:
>> >> Ready to process requests
>> >> Waking up in 0.3 seconds.
>> >> (0) Received Access-Request Id 226 from 127.0.0.1:38763 to
>> 127.0.0.1:1812 length 92
>> >> (0)   User-Name = ">> >> user at mydomain.com <mailto:user at mydomain.com>>>  <>> mailto:user at mydomain.com <mailto:mailto:user at mydomain.com>>> >>> "
>> >> (0)   User-Password = "password123456"
>> >> (0)   NAS-IP-Address = 127.0.1.1
>> >> (0)   NAS-Port = 18120
>> >> (0)   Message-Authenticator = 0x53b836642c653e776b0d9f8a542fca3a
>> >> (0) # Executing section authorize from file
>> /etc/freeradius/3.0/sites-enabled/default
>> >> (0) pap: WARNING: No "known good" password found for the user.  Not
>> setting Auth-Type
>> >> (0) pap: WARNING: Authentication will fail unless a "known good"
>> password is available
>> >> (0) # Executing group from file
>> /etc/freeradius/3.0/sites-enabled/default
>> >> Waking up in 0.3 seconds.
>> >> Waking up in 0.2 seconds.
>> >> (0) pam: ERROR: pam_authenticate failed: Authentication failure
>> >> (0) # Executing group from file
>> /etc/freeradius/3.0/sites-enabled/default
>> >> Waking up in 0.7 seconds.
>> >> (0) Sent Access-Reject Id 226 from 127.0.0.1:1812 to 127.0.0.1:38763
>> length 20
>> >> Waking up in 3.9 seconds.
>> >> Ready to process requests
>> >>
>> >> Regards
>> >>
>> >>
>> >>
>> -
>> List info/subscribe/unsubscribe? See
>> http://www.freeradius.org/list/users.html <http://www.freeradius.org/list/users.html>
> -
> List info/subscribe/unsubscribe? See > http://www.freeradius.org/list/users.html <http://www.freeradius.org/list/users.html>


More information about the Freeradius-Users mailing list