Hello, My apologies. This was my poor attempt at providing enough information, but not having to censor the output as much. Here is a fully debug for a few attempts with unique information censored out. I appreciate the response. rad_recv: Access-Request packet from host xxx.xxx.xx.xxx port 1645, id=249, length=430 X-Ascend-Send-Auth = Send-Auth-CHAP CHAP-Challenge = 0x7edf2cf58afb187156d7c4ade27330a92ecf5c653aeb48e106c7f41d92636019debf8cd5eadb7851b6b7248d425390898eafbc459acba8c166 CHAP-Password = 0x00f1d4017f883771443194ba6eb2e32dbd User-Name = "mktest" Called-Station-Id = "test-called-station-id" Calling-Station-Id = "xxx-xxx-xxxx" Framed-Protocol = GPRS-PDP-Context 3GPP-IMSI = "IMSI#" 3GPP-Charging-ID = charging-id 3GPP-PDP-Type = 0 3GPP-Charging-Gateway-Address = xxx.xx.xxx.xx 3GPP-GPRS-Negotiated-QoS-profile = "99-13921F739697E874820101" 3GPP-SGSN-Address = xxx.xxx.xx.xx 3GPP-GGSN-Address = xxx.xxx.xxx.xx 3GPP-IMSI-MCC-MNC = "310410" 3GPP-GGSN-MCC-MNC = "000000" 3GPP-NSAPI = "5" 3GPP-Selection-Mode = "0" 3GPP-Charging-Characteristics = "0800" 3GPP-SGSN-MCC-MNC = "310410" 3GPP-RAT-Type = 1 3GPP-Location-Info = 0x01130014d8eb1e7d 3GPP-Attr-23 = 0x8a01 3GPP-IMEISV = "S&Q@ \txP" NAS-Port-Type = Virtual NAS-Port = 60000 NAS-Port-Id = "GGSN" Service-Type = Framed-User NAS-IP-Address = xxx.xxx.xx.xxx NAS-Identifier = "nas-identifier" # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [chap] Setting 'Auth-Type := CHAP' ++[chap] returns ok ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "mktest", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop ++[files] returns noop [sql] expand: %{User-Name} -> mktest [sql] sql_set_user escaped user --> 'mktest' rlm_sql (sql): Reserving sql socket id: 9 [sql] expand: SELECT id, UserName, chk_Attribute, password, chk_op FROM modemAuth WHERE UserName = '%{SQL-User-Name}' and status='active' ORDER BY id -> SELECT id, UserName, chk_Attribute, password, chk_op FROM modemAuth WHERE UserName = 'mktest' and status='active' ORDER BY id rlm_sql_mysql: query: SELECT id, UserName, chk_Attribute, password, chk_op FROM modemAuth WHERE UserName = 'mktest' and status='active' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, UserName, rpl_Attribute, IP, rpl_op FROM modemAuth WHERE UserName = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, rpl_Attribute, IP, rpl_op FROM modemAuth WHERE UserName = 'mktest' ORDER BY id rlm_sql_mysql: query: SELECT id, UserName, rpl_Attribute, IP, rpl_op FROM modemAuth WHERE UserName = 'mktest' ORDER BY id rlm_sql (sql): Released sql socket id: 9 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = CHAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group CHAP {...} [chap] login attempt by "mktest" with CHAP password [chap] Using clear text password "1234567" for user mktest authentication. [chap] Password check failed ++[chap] returns reject Failed to authenticate the user. Login incorrect (rlm_chap: Wrong user password): [mktest/<CHAP-Password>] (from client modemAuth port 60000 cli xxx-xxx-xxxx) Using Post-Auth-Type Reject # Executing group from file /etc/raddb/sites-enabled/default +- entering group REJECT {...} [sql] expand: %{User-Name} -> mktest [sql] sql_set_user escaped user --> 'mktest' [sql] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [sql] ... expanding second conditional [sql] expand: Chap-Password -> Chap-Password [sql] expand: INSERT into radpostauth (id, user, pass, reply, date) values ('', '%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW()) -> INSERT into radpostauth (id, user, pass, reply, date) values ('', 'mktest', 'Chap-Password', 'Access-Reject', NOW()) [sql] expand: /data/radius/radsqltrace.sql -> /data/radius/radsqltrace.sql rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (id, user, pass, reply, date) values ('', 'mktest', 'Chap-Password', 'Access-Reject', NOW()) rlm_sql (sql): Reserving sql socket id: 8 rlm_sql_mysql: query: INSERT into radpostauth (id, user, pass, reply, date) values ('', 'mktest', 'Chap-Password', 'Access-Reject', NOW()) rlm_sql (sql): Released sql socket id: 8 ++[sql] returns ok [attr_filter.access_reject] expand: %{User-Name} -> mktest attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 0 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 0 Sending Access-Reject of id 249 to xxx.xxx.xx.xxx port 1645 Waking up in 4.9 seconds. Cleaning up request 0 ID 249 with timestamp +104 Ready to process requests. rad_recv: Access-Request packet from host xxx.xxx.xx.xxx port 1645, id=149, length=430 X-Ascend-Send-Auth = Send-Auth-CHAP CHAP-Challenge = 0x7edf2cf58afb187156d7c4ade27330a92ecf5c653aeb48e106c7f41d92636019debf8cd5eadb7851b6b7248d425390898eafbc459acba8c166 CHAP-Password = 0x00f1d4017f883771443194ba6eb2e32dbd User-Name = "mktest" Called-Station-Id = "test-called-station-id" Calling-Station-Id = "xxx-xxx-xxxx" Framed-Protocol = GPRS-PDP-Context 3GPP-IMSI = "IMSI#" 3GPP-Charging-ID = 270564512 3GPP-PDP-Type = 0 3GPP-Charging-Gateway-Address = xxx.xx.xxx.xx 3GPP-GPRS-Negotiated-QoS-profile = "99-13921F739697E874820101" 3GPP-SGSN-Address = xxx.xxx.xx.xx 3GPP-GGSN-Address = xxx.xxx.xxx.xx 3GPP-IMSI-MCC-MNC = "310410" 3GPP-GGSN-MCC-MNC = "000000" 3GPP-NSAPI = "5" 3GPP-Selection-Mode = "0" 3GPP-Charging-Characteristics = "0800" 3GPP-SGSN-MCC-MNC = "310410" 3GPP-RAT-Type = 1 3GPP-Location-Info = 0x01130014d8eb1e7d 3GPP-Attr-23 = 0x8a01 3GPP-IMEISV = "S&Q@ \txP" NAS-Port-Type = Virtual NAS-Port = 60000 NAS-Port-Id = "GGSN" Service-Type = Framed-User NAS-IP-Address = xxx.xxx.xx.xxx NAS-Identifier = "nas-identifier" # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [chap] Setting 'Auth-Type := CHAP' ++[chap] returns ok ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "mktest", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop ++[files] returns noop [sql] expand: %{User-Name} -> mktest [sql] sql_set_user escaped user --> 'mktest' rlm_sql (sql): Reserving sql socket id: 7 [sql] expand: SELECT id, UserName, chk_Attribute, password, chk_op FROM modemAuth WHERE UserName = '%{SQL-User-Name}' and status='active' ORDER BY id -> SELECT id, UserName, chk_Attribute, password, chk_op FROM modemAuth WHERE UserName = 'mktest' and status='active' ORDER BY id rlm_sql_mysql: query: SELECT id, UserName, chk_Attribute, password, chk_op FROM modemAuth WHERE UserName = 'mktest' and status='active' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, UserName, rpl_Attribute, IP, rpl_op FROM modemAuth WHERE UserName = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, rpl_Attribute, IP, rpl_op FROM modemAuth WHERE UserName = 'mktest' ORDER BY id rlm_sql_mysql: query: SELECT id, UserName, rpl_Attribute, IP, rpl_op FROM modemAuth WHERE UserName = 'mktest' ORDER BY id rlm_sql (sql): Released sql socket id: 7 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = CHAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group CHAP {...} [chap] login attempt by "mktest" with CHAP password [chap] Using clear text password "1234567" for user mktest authentication. [chap] Password check failed ++[chap] returns reject Failed to authenticate the user. Login incorrect (rlm_chap: Wrong user password): [mktest/<CHAP-Password>] (from client modemAuth port 60000 cli xxx-xxx-xxxx) Using Post-Auth-Type Reject # Executing group from file /etc/raddb/sites-enabled/default +- entering group REJECT {...} [sql] expand: %{User-Name} -> mktest [sql] sql_set_user escaped user --> 'mktest' [sql] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [sql] ... expanding second conditional [sql] expand: Chap-Password -> Chap-Password [sql] expand: INSERT into radpostauth (id, user, pass, reply, date) values ('', '%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW()) -> INSERT into radpostauth (id, user, pass, reply, date) values ('', 'mktest', 'Chap-Password', 'Access-Reject', NOW()) [sql] expand: /data/radius/radsqltrace.sql -> /data/radius/radsqltrace.sql rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (id, user, pass, reply, date) values ('', 'mktest', 'Chap-Password', 'Access-Reject', NOW()) rlm_sql (sql): Reserving sql socket id: 6 rlm_sql_mysql: query: INSERT into radpostauth (id, user, pass, reply, date) values ('', 'mktest', 'Chap-Password', 'Access-Reject', NOW()) rlm_sql (sql): Released sql socket id: 6 ++[sql] returns ok [attr_filter.access_reject] expand: %{User-Name} -> mktest attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 1 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 1 Sending Access-Reject of id 149 to xxx.xxx.xx.xxx port 1645 Waking up in 4.9 seconds. Cleaning up request 1 ID 149 with timestamp +170 Ready to process requests. rad_recv: Access-Request packet from host xxx.xxx.xx.xxx port 1645, id=30, length=430 X-Ascend-Send-Auth = Send-Auth-CHAP CHAP-Challenge = 0x7edf2cf58afb187156d7c4ade27330a92ecf5c653aeb48e106c7f41d92636019debf8cd5eadb7851b6b7248d425390898eafbc459acba8c166 CHAP-Password = 0x00f1d4017f883771443194ba6eb2e32dbd User-Name = "mktest" Called-Station-Id = "test-called-station-id" Calling-Station-Id = "xxx-xxx-xxxx" Framed-Protocol = GPRS-PDP-Context 3GPP-IMSI = "IMSI#" 3GPP-Charging-ID = 270564773 3GPP-PDP-Type = 0 3GPP-Charging-Gateway-Address = xxx.xx.xxx.xx 3GPP-GPRS-Negotiated-QoS-profile = "99-13921F739697E874820101" 3GPP-SGSN-Address = xxx.xxx.xx.xx 3GPP-GGSN-Address = xxx.xxx.xxx.xx 3GPP-IMSI-MCC-MNC = "310410" 3GPP-GGSN-MCC-MNC = "000000" 3GPP-NSAPI = "5" 3GPP-Selection-Mode = "0" 3GPP-Charging-Characteristics = "0800" 3GPP-SGSN-MCC-MNC = "310410" 3GPP-RAT-Type = 1 3GPP-Location-Info = 0x01130014d8eb1e7d 3GPP-Attr-23 = 0x8a01 3GPP-IMEISV = "S&Q@ \txP" NAS-Port-Type = Virtual NAS-Port = 60000 NAS-Port-Id = "GGSN" Service-Type = Framed-User NAS-IP-Address = xxx.xxx.xx.xxx NAS-Identifier = "nas-identifier" # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [chap] Setting 'Auth-Type := CHAP' ++[chap] returns ok ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "mktest", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop ++[files] returns noop [sql] expand: %{User-Name} -> mktest [sql] sql_set_user escaped user --> 'mktest' rlm_sql (sql): Reserving sql socket id: 5 [sql] expand: SELECT id, UserName, chk_Attribute, password, chk_op FROM modemAuth WHERE UserName = '%{SQL-User-Name}' and status='active' ORDER BY id -> SELECT id, UserName, chk_Attribute, password, chk_op FROM modemAuth WHERE UserName = 'mktest' and status='active' ORDER BY id rlm_sql_mysql: query: SELECT id, UserName, chk_Attribute, password, chk_op FROM modemAuth WHERE UserName = 'mktest' and status='active' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, UserName, rpl_Attribute, IP, rpl_op FROM modemAuth WHERE UserName = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, rpl_Attribute, IP, rpl_op FROM modemAuth WHERE UserName = 'mktest' ORDER BY id rlm_sql_mysql: query: SELECT id, UserName, rpl_Attribute, IP, rpl_op FROM modemAuth WHERE UserName = 'mktest' ORDER BY id rlm_sql (sql): Released sql socket id: 5 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = CHAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group CHAP {...} [chap] login attempt by "mktest" with CHAP password [chap] Using clear text password "1234567" for user mktest authentication. [chap] Password check failed ++[chap] returns reject Failed to authenticate the user. Login incorrect (rlm_chap: Wrong user password): [mktest/<CHAP-Password>] (from client modemAuth port 60000 cli xxx-xxx-xxxx) Using Post-Auth-Type Reject # Executing group from file /etc/raddb/sites-enabled/default +- entering group REJECT {...} [sql] expand: %{User-Name} -> mktest [sql] sql_set_user escaped user --> 'mktest' [sql] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [sql] ... expanding second conditional [sql] expand: Chap-Password -> Chap-Password [sql] expand: INSERT into radpostauth (id, user, pass, reply, date) values ('', '%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW()) -> INSERT into radpostauth (id, user, pass, reply, date) values ('', 'mktest', 'Chap-Password', 'Access-Reject', NOW()) [sql] expand: /data/radius/radsqltrace.sql -> /data/radius/radsqltrace.sql rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (id, user, pass, reply, date) values ('', 'mktest', 'Chap-Password', 'Access-Reject', NOW()) rlm_sql (sql): Reserving sql socket id: 4 rlm_sql_mysql: query: INSERT into radpostauth (id, user, pass, reply, date) values ('', 'mktest', 'Chap-Password', 'Access-Reject', NOW()) rlm_sql (sql): Released sql socket id: 4 ++[sql] returns ok [attr_filter.access_reject] expand: %{User-Name} -> mktest attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 2 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 2 Sending Access-Reject of id 30 to xxx.xxx.xx.xxx port 1645 Waking up in 4.9 seconds. Cleaning up request 2 ID 30 with timestamp +231 Ready to process requests. On Mon, Apr 16, 2012 at 11:32 PM, Alan DeKok <aland@deployingradius.com> wrote:
GT4NE1 wrote:
We're thinking it might have to do with the CHAP challenge length that gets sent by these new modems, or more specifically, the new radio module in them. From packet captures, the same length gets sent every time (59), but fails with the
Except that the debug output you posted shows *nothing* about the Access-Request.
every time. Successful attempts from other modems have varying length up to 50 from what I've seen. Is there a higher level of debug I can turn on to see what CHAP is failing even though the correct username and password are being supplied or is there a CHAP setting somewhere specifies maximum challenge length?
FreeRADIUS has *no* limit on the CHAP-Challenge. It can handle challenges up to 253 octets, which is the maximum length of RADIUS attributes.
If CHAP is failing, it's because the client is calculating the wrong CHAP-Password.
I'm told these modems were successfully tested against a Juniper RADIUS server. Below is the debug output and my freeradius version. Any help would be greatly appreciated.
There is no CHAP-Challenge in the debug output. You've helpfully deleted the entire contents of the Access-Request.
For all that's holy, *WHY* do people insist on doing this? The FAQ, README, "man" page, web pages, and daily messages on this list say "post the debug output". They DON'T say "butcher the debug output, and post small pieces of it."
If you want us to help you, the ask *good* questions. Asking a question about a CHAP-Challenge, and then *not* including it in the debug output is a *bad* thing to do.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html