Problems with Freeradius password encryption

[Andrei Petru Mura]

I'm trying to do some performance tests with FR 2.1.10. I'm using radperf
tool. I have two different machines with freeradius installed on them. In
one of them the test is going well for now, but in the other (where I'm
more interested on) the test fails with the following error:

rad_recv: Access-Reject packet from host 127.0.0.1 port 1812, id=50,
length=20
rad_verify: Received Access-Reject packet from client 127.0.0.1 port 1812
with invalid signature (err=2)!  (Shared secret is incorrect.)

Bellow I'll put the output from the freeradius run with -XXX with some
comments on it:

rad_recv: Access-Request packet from host 127.0.0.1 port 38027, id=50,
length=45
User-Name = "test1"
User-Password = "\340<V#\307\177\221\034\355\366M\255\364\271\340\253"

/*** comment 1:
the User-Password on the machine with well-working freeradius isn't
encrypted. It looks simple like this:

User-Password = "test1"

***/

Mon Jul 23 11:36:48 2012 : Info: # Executing section authorize from file
/netnfork/radius//etc/raddb/sites-enabled/default
Mon Jul 23 11:36:48 2012 : Info: +- entering group authorize {...}
Mon Jul 23 11:36:48 2012 : Info: ++[preprocess] returns ok
Mon Jul 23 11:36:48 2012 : Info: ++[chap] returns noop
Mon Jul 23 11:36:48 2012 : Info: [suffix] No '@' in User-Name = "test1",
looking up realm NULL
Mon Jul 23 11:36:48 2012 : Info: [suffix] No such realm "NULL"
Mon Jul 23 11:36:48 2012 : Info: ++[suffix] returns noop
Mon Jul 23 11:36:48 2012 : Info: [eap] No EAP-Message, not doing EAP
Mon Jul 23 11:36:48 2012 : Info: ++[eap] returns noop
Mon Jul 23 11:36:48 2012 : Info: [sql] expand: %{User-Name} -> test1
Mon Jul 23 11:36:48 2012 : Info: [sql] sql_set_user escaped user --> 'test1'
Mon Jul 23 11:36:48 2012 : Debug: rlm_sql (sql): Reserving sql socket id: 0
Mon Jul 23 11:36:48 2012 : Info: [sql] expand: SELECT id, UserName,
Attribute, Value, Op   FROM radcheck   WHERE Username = '%{SQL-User-Name}'
  ORDER BY id -> SELECT id, UserName, Attribute, Value, Op   FROM radcheck
  WHERE Username = 'test1'   ORDER BY id
Mon Jul 23 11:36:48 2012 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OK
Mon Jul 23 11:36:48 2012 : Debug: rlm_sql_postgresql: query affected rows =
1 , fields = 5
Mon Jul 23 11:36:48 2012 : Info: [sql] User found in radcheck table
Mon Jul 23 11:36:48 2012 : Info: [sql] expand: SELECT id, UserName,
Attribute, Value, Op   FROM radreply   WHERE Username = '%{SQL-User-Name}'
  ORDER BY id -> SELECT id, UserName, Attribute, Value, Op   FROM radreply
  WHERE Username = 'test1'   ORDER BY id
Mon Jul 23 11:36:48 2012 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OK
Mon Jul 23 11:36:48 2012 : Debug: rlm_sql_postgresql: query affected rows =
0 , fields = 5
Mon Jul 23 11:36:48 2012 : Info: [sql] expand: SELECT GroupName FROM
radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority -> SELECT
GroupName FROM radusergroup WHERE UserName='test1' ORDER BY priority
Mon Jul 23 11:36:48 2012 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OK
Mon Jul 23 11:36:48 2012 : Debug: rlm_sql_postgresql: query affected rows =
0 , fields = 1
Mon Jul 23 11:36:48 2012 : Debug: rlm_sql (sql): Released sql socket id: 0
Mon Jul 23 11:36:48 2012 : Info: ++[sql] returns ok
Mon Jul 23 11:36:48 2012 : Info: ++[expiration] returns noop
Mon Jul 23 11:36:48 2012 : Info: ++[logintime] returns noop
Mon Jul 23 11:36:48 2012 : Info: ++[pap] returns updated
Mon Jul 23 11:36:48 2012 : Info: Found Auth-Type = PAP
Mon Jul 23 11:36:48 2012 : Info: # Executing group from file
/netnfork/radius//etc/raddb/sites-enabled/default
Mon Jul 23 11:36:48 2012 : Info: +- entering group PAP {...}
Mon Jul 23 11:36:48 2012 : Info: [pap] login attempt with password
"�<V#�??��M�����"
Mon Jul 23 11:36:48 2012 : Info: [pap] Using clear text password "test1"
Mon Jul 23 11:36:48 2012 : Info: [pap] Passwords don't match
Mon Jul 23 11:36:48 2012 : Info: ++[pap] returns reject

/*** comment 2:

the last four lines in the well-working server are:

Mon Jul 23 11:32:15 2012 : Info: [pap] login attempt with password "test92"
Mon Jul 23 11:32:15 2012 : Info: [pap] Using clear text password "test92"
Mon Jul 23 11:32:15 2012 : Info: [pap] User authenticated successfully
Mon Jul 23 11:32:15 2012 : Info: ++[pap] returns ok

***/


Mon Jul 23 11:36:48 2012 : Info: Failed to authenticate the user.
Mon Jul 23 11:36:48 2012 : Debug:   WARNING: Unprintable characters in the
password.  Double-check the shared secret on the server and the NAS!
Mon Jul 23 11:36:48 2012 : Info: Using Post-Auth-Type Reject
Mon Jul 23 11:36:48 2012 : Info: # Executing group from file
/netnfork/radius//etc/raddb/sites-enabled/default
Mon Jul 23 11:36:48 2012 : Info: +- entering group REJECT {...}
Mon Jul 23 11:36:48 2012 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> test1
Mon Jul 23 11:36:48 2012 : Debug: attr_filter: Matched entry DEFAULT at
line 11
Mon Jul 23 11:36:48 2012 : Info: ++[attr_filter.access_reject] returns
updated
Mon Jul 23 11:36:48 2012 : Info: Delaying reject of request 3 for 1 seconds
Mon Jul 23 11:36:48 2012 : Debug: Going to the next request
Mon Jul 23 11:36:48 2012 : Debug: Waking up in 0.9 seconds.
Mon Jul 23 11:36:49 2012 : Info: Sending delayed reject for request 3
Sending Access-Reject of id 50 to 127.0.0.1 port 38027
Mon Jul 23 11:36:49 2012 : Debug: Waking up in 4.9 seconds.
Mon Jul 23 11:36:54 2012 : Info: Cleaning up request 3 ID 50 with timestamp
+250
Mon Jul 23 11:36:54 2012 : Info: Ready to process requests.

>From the output I understand that the password shouldn't be encrypted when
is sent. Can anybody suggest me how to fix that problem?
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20120723/0964e38b/attachment-0001.html>