Issue while geting authentication via PrivacyIdea

Hello!

I have an issue geting authenticate on system(my case is pam system) via PrivacyIdea.

I have test and prod instance of Pidea - the same version(3.8.1), FreeRADIUS Version 3.0.26

When I try to authenticate via Pidea on my prod env I get such log in freeradius.log:

Prod pidea reject:
Thu May  4 11:53:53 2023 : Info: rlm_perl: Config File /etc/privacyidea/rlm_perl.ini found!
Thu May  4 11:53:53 2023 : Info: rlm_perl: Debugging config:
Thu May  4 11:53:53 2023 : Info: rlm_perl: Default URL https://localhost/validate/check
Thu May  4 11:53:53 2023 : Info: rlm_perl: Looking for config for auth-type Perl
Thu May  4 11:53:53 2023 : Info: rlm_perl: Could not find valid password encoding. Sending password as-is.
Thu May  4 11:53:53 2023 : rlm_perl: No appropriate encodings found!
Thu May  4 11:53:53 2023 : Info: rlm_perl: Setting client IP to 10.*.*.*.
Thu May  4 11:53:53 2023 : Info: rlm_perl: Auth-Type: Perl
Thu May  4 11:53:53 2023 : Info: rlm_perl: url: https://localhost/validate/check
Thu May  4 11:53:53 2023 : Info: rlm_perl: user sent to privacyidea: MYUSER
Thu May  4 11:53:53 2023 : Info: rlm_perl: realm sent to privacyidea:
Thu May  4 11:53:53 2023 : Info: rlm_perl: resolver sent to privacyidea:
Thu May  4 11:53:53 2023 : Info: rlm_perl: client sent to privacyidea: 10.*.*.*
Thu May  4 11:53:53 2023 : Info: rlm_perl: state sent to privacyidea:
Thu May  4 11:53:53 2023 : Info: rlm_perl: urlparam client
Thu May  4 11:53:53 2023 : Info: rlm_perl: urlparam user
Thu May  4 11:53:53 2023 : Info: rlm_perl: urlparam pass
Thu May  4 11:53:53 2023 : Info: rlm_perl: Request timeout: 10
Thu May  4 11:53:53 2023 : Info: rlm_perl: Not verifying SSL certificate!
Thu May  4 11:53:54 2023 : Info: rlm_perl: elapsed time for privacyidea call: 0.561893
Thu May  4 11:53:54 2023 : Info: rlm_perl: privacyIDEA Result status is true!
Thu May  4 11:53:54 2023 : Info: rlm_perl: privacyIDEA access denied for MYUSERrealm=''
Thu May  4 11:53:54 2023 : Info: rlm_perl: return RLM_MODULE_REJECT

When I try to authenticate via my test Pidea, everything works fine:

Test pidea access:
Fri May  5 09:46:19 2023 : Info: rlm_perl: Config File /etc/privacyidea/rlm_perl.ini found!
Fri May  5 09:46:19 2023 : Info: rlm_perl: Debugging config:
Fri May  5 09:46:19 2023 : Info: rlm_perl: Default URL https://localhost/validate/check
Fri May  5 09:46:19 2023 : Info: rlm_perl: Looking for config for auth-type Perl
Fri May  5 09:46:19 2023 : Info: rlm_perl: Password encoding guessed: ascii
Fri May  5 09:46:19 2023 : Info: rlm_perl: Setting client IP to 10.*.*.*.
Fri May  5 09:46:19 2023 : Info: rlm_perl: Auth-Type: Perl
Fri May  5 09:46:19 2023 : Info: rlm_perl: url: https://localhost/validate/check
Fri May  5 09:46:19 2023 : Info: rlm_perl: user sent to privacyidea: MYUSER
Fri May  5 09:46:19 2023 : Info: rlm_perl: realm sent to privacyidea:
Fri May  5 09:46:19 2023 : Info: rlm_perl: resolver sent to privacyidea:
Fri May  5 09:46:19 2023 : Info: rlm_perl: client sent to privacyidea: 10.*.*.*
Fri May  5 09:46:19 2023 : Info: rlm_perl: state sent to privacyidea:
Fri May  5 09:46:19 2023 : Info: rlm_perl: urlparam client
Fri May  5 09:46:19 2023 : Info: rlm_perl: urlparam pass
Fri May  5 09:46:19 2023 : Info: rlm_perl: urlparam user
Fri May  5 09:46:20 2023 : Info: rlm_perl: Request timeout: 10
Fri May  5 09:46:20 2023 : Info: rlm_perl: Not verifying SSL certificate!
Fri May  5 09:46:22 2023 : Info: rlm_perl: elapsed time for privacyidea call: 2.236184
Fri May  5 09:46:22 2023 : Info: rlm_perl: privacyIDEA Result status is true!
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++ Parsing group: Attribute
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++ Found member 'Attribute Filter-Id'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ Attribute: IF ''->'' == '' THEN 'Filter-Id'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ no directory
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++++ User attribute is a string:
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++++ trying to match
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++++ Result: No match, no RADIUS attribute Filter-Id added.
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++ Found member 'Attribute otherAttribute'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ Attribute: IF ''->'' == '' THEN 'otherAttribute'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ no directory
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++++ User attribute is a string:
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++++ trying to match
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++++ Result: No match, no RADIUS attribute otherAttribute added.
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++ Found member 'Attribute Filter-ID'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ Attribute: IF 'user'->'Fortinet-Group-Name' == 'CN=(\S+_OTP)' THEN 'Filter-ID'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ searching in directory user
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++++ User attribute is a string:
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++++ trying to match
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++++ Result: No match, no RADIUS attribute Filter-ID added.
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++ Found member 'Attribute Fortinet-Group-Name'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ Attribute: IF 'user'->'memberOf' == 'CN=(\S+_OTP)' THEN 'Fortinet-Group-Name'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ searching in directory user
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++++ User attribute is a string:
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++++ trying to match
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++++ Result: No match, no RADIUS attribute Fortinet-Group-Name added.
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++ Found member 'Attribute Class'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ Attribute: IF ''->'' == '' THEN 'Class'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ no directory
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++++ User attribute is a string:
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++++ trying to match
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++++ Result: No match, no RADIUS attribute Class added.
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++ Parsing group: Mapping
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++++ Found member 'Mapping user'
Fri May  5 09:46:22 2023 : Info: rlm_perl: ++++++ Map: user : group -> Class
Fri May  5 09:46:22 2023 : Info: rlm_perl: +++ Map: serial -> privacyIDEA-Serial
Fri May  5 09:46:22 2023 : Info: rlm_perl: return RLM_MODULE_HANDLED

Looks that problem is in this:

...
Thu May  4 11:53:53 2023 : Info: rlm_perl: Looking for config for auth-type Perl
Thu May  4 11:53:53 2023 : Info: rlm_perl: Could not find valid password encoding. Sending password as-is.
Thu May  4 11:53:53 2023 : rlm_perl: No appropriate encodings found!
...

On my test it looks like this:

...
Fri May  5 09:42:11 2023 : Info: rlm_perl: Looking for config for auth-type Perl
Fri May  5 09:42:11 2023 : Info: rlm_perl: Password encoding guessed: ascii
...

I’ve got encodings list using this code:

#!/usr/bin/env perl
use Encode;
@list = Encode->encodings();
print @list

My prod Pidea:

asciiascii-ctrlcp1252iso-8859-1nullutf-8-strictutf8

My test Pidea:

asciiascii-ctrlcp1252iso-8859-1nullutf-8-strictutf8

Also I’ve noticed the order of urlparam:
My prod:

Thu May  4 11:53:53 2023 : Info: rlm_perl: urlparam client
Thu May  4 11:53:53 2023 : Info: rlm_perl: urlparam user
Thu May  4 11:53:53 2023 : Info: rlm_perl: urlparam pass

My test:

Fri May  5 09:42:11 2023 : Info: rlm_perl: urlparam client
Fri May  5 09:42:11 2023 : Info: rlm_perl: urlparam pass
Fri May  5 09:42:11 2023 : Info: rlm_perl: urlparam user

Any clues, please?

P.S. Also I’ve figured out that password for my Pidea Prod is sent like:

??d??4??r?9?v???
OR
??V?ͭ???�!prV#

While on Pidea Test I’ve got plain text password.

Also my Pidea Prod use https, while Pidea Test has no ssl cert.

Though other systems use Pidea Prod normally(also got plaintext password in $password variable of vim /usr/share/privacyidea/freeradius/privacyidea_radius.pm).

Also, I think it’s a security concern, that pidea admin can easily get all domain’s users password in plain text, for example in the same /var/freeradius/radius.log.
Just add something like this in your privacyidea_radius.pm file:

radiusd::radlog( Info, "Password is: $password");

in the end of if code below:

if ( ! ref($decoder) ) {
            radiusd::radlog( Info, "Could not find valid password encoding. Sending password as-is." );
            radiusd::radlog( Debug, $decoder );
            radiusd::radlog( Info, 'Using ascii decoder by default' );
            $password = decode("ascii", $password);
} else {
            &radiusd::radlog( Info, "Password encoding guessed: " . $decoder->name);
            $password = $decoder->decode($password);
        }
        $params{"pass"} = $password;

radiusd::radlog( Info, "Password is: $password");

Changing type of TLS/Starttls work neither.

I’ve set ssl cert for my Pidea Test - and still it works fine.


This is audit message when try to authenticate on my Pidea Prod. It says “wrong otp pin” though I have no OTP window to enter it. It breaks before this window.

Any thoughts?
Looks like something else between my pam system and Pidea is encrypting data, but there is nothing.

  1. Ensure that are using the correct RADIUS shared secret.
  2. Be aware, that privacyIDEA expects an OTPPIN+OTPvalue, or a PASSWORD+OTPValue or simply the OTPvalue depending on your policy configuration.
  1. Radius secret is ok on both installations(otherwise I have no logs like I’ve mentioned in the first post, logs would contain string like “client is not authorized to make request”).
  2. Auth policy is the same on both hosts(AD users enter their domain passwords, then get the input form for otp:

The main difference that my pam system is resolve password as ascii for Pidea Test instance:

...
Fri May  5 09:42:11 2023 : Info: rlm_perl: Looking for config for auth-type Perl
Fri May  5 09:42:11 2023 : Info: rlm_perl: Password encoding guessed: ascii
...

and the same system on my Pidea prod gets:

...
Thu May  4 11:53:53 2023 : Info: rlm_perl: Looking for config for auth-type Perl
Thu May  4 11:53:53 2023 : Info: rlm_perl: Could not find valid password encoding. Sending password as-is.
Thu May  4 11:53:53 2023 : rlm_perl: No appropriate encodings found!
...

though the other systems works fine on Pidea prod and passwords resolves as ascii.

Another portion of logs found in /var/log/privacyidea/privacyidea.log

[2023-05-18 15:28:25,353][497270][139993677637184][INFO][privacyidea.lib.user:262] user 'MYUSER' found in resolver '***'
[2023-05-18 15:28:25,353][497270][139993677637184][INFO][privacyidea.lib.user:264] userid resolved to '86b04571-6faa-44cc-a5d1-a5b3fc63b4dc'
[2023-05-18 15:28:25,419][497270][139993677637184][INFO][privacyidea.lib.user:432] User 'MYUSER' from realm 'mydomain.com' tries to authenticate
[2023-05-18 15:28:25,424][497270][139993677637184][WARNING][privacyidea.lib.resolvers.LDAPIdResolver:395] failed to check password for '86b04571-6faa-44cc-a5d1-a5b3fc63b4dc'/'CN=MYUSER,***': LDAPSASLPrepError('SASLprep error: non-ASCII control character present')
[2023-05-18 15:28:25,424][497270][139993677637184][INFO][privacyidea.lib.user:444] user User(login='MYUSER', realm='mydomain.com', resolver='***') failed to authenticate.

So, what is it? What can cause it?

SASLprep error: non-ASCII control character present

Still my guess: Your shared secrets do not match.

Reduce complexity, which makes debugging easier for you.

Recheck the shared secret.
Choose a simple password with the low 7 bits.

No.Such log text does not exist in FreeRADIUS.

So, the solution for me:
Just reinstall my target system from scratch and everything works fine now.
Radius secrets are same(did not changed them).
My guess - bad .ova images of my target system.

cornelinux - thank you for your replies.