Failure to Process radgroupreply

[Andrew Long]

For reference, here is a debug from another account's auth request
which successfully processes radgroupreply and sends the pairs from
that table. The attributes are different here because the NAS is
different and I don't want to confuse it by assigning another vendor's
attributes. I did accidentally have the Nomadix-Bw-Up/Down in this
account's radgrouprely table, and they were also passed correctly
here, though I don't have that debug.


rad_recv: Access-Request packet from host xx.xx.xx.xx port 32772,
id=71, length=244
  Acct-Session-Id = "645dcb12"
  NAS-Port = 10
  NAS-Port-Type = Wireless-802.11
  User-Name = "tup140412"
  Calling-Station-Id = "3C-8B-FE-D8-66-6E"
  Called-Station-Id = "3C-D9-2B-7B-97-37"
  Framed-IP-Address = 192.168.25.92
  MS-CHAP2-Response =
0x4700c5c9e5b0d32cef356ea40cef22e904a400000000000000008ab1f953dbb0a3b342fbdf00518cda391b29bf13efeffd84
  MS-CHAP-Challenge = 0x20a511804f668694117f916ee1ef6a46
  NAS-Identifier = "TW126LK026"
  NAS-IP-Address = xx.xx.xx.xx
  Framed-MTU = 1496
  Connect-Info = "HTTPS"
  Service-Type = Framed-User
  Colubris-AVPair = "vsc-name=HP ProCurve"
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
[mschap] Found MS-CHAP attributes.  Setting 'Auth-Type  = mschap'
++[mschap] returns ok
[suffix] No '@' in User-Name = "tup140412", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[sql]   expand: %{User-Name} -> tup140412
[sql] sql_set_user escaped user --> 'tup140412'
rlm_sql (sql): Reserving sql socket id: 2
[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 =
'tup140412' ORDER BY id
[sql] User found in radcheck table
[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 =
'tup140412' ORDER BY id
[sql]   expand: SELECT groupname FROM radusergroup WHERE username =
'%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM
radusergroup WHERE username = 'tup140412' ORDER BY priority
[sql]   expand: SELECT id, groupname, attribute, Value, op FROM
radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT
id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname
= 'hieTUPELO-guest-group' ORDER BY id
[sql] User found in group hieTUPELO-guest-group
[sql]   expand: SELECT id, groupname, attribute, value, op FROM
radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT
id, groupname, attribute, value, op FROM radgroupreply WHERE groupname
= 'hieTUPELO-guest-group' ORDER BY id
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[noresetcounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[dailycounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[monthlycounter] returns noop
rlm_sqlcounter: Entering module authorize code
rlm_sqlcounter: Could not find Check item value pair
++[daypasscounter] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
Found Auth-Type = MSCHAP
+- entering group MS-CHAP {...}
[mschap] Told to do MS-CHAPv2 for tup140412 with NT-Password
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
Login OK: [tup140412] (from client xxx-gateway port 10 cli 3C-8B-FE-D8-66-6E)
+- entering group post-auth {...}
[sql]   expand: %{User-Name} -> tup140412
[sql] sql_set_user escaped user --> 'tup140412'
[sql]   expand: %{User-Password} ->
[sql]   ... expanding second conditional
[sql]   expand: %{Chap-Password} ->
[sql]   expand: INSERT INTO radpostauth (username, pass, reply,
authdate) VALUES ( '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
-> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES (
'tup140412', '', 'Access-Accept', '2012-04-05 08:01:35')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth
(username, pass, reply, authdate) VALUES ( 'tup140412', '',
'Access-Accept', '2012-04-05 08:01:35')
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
++[exec] returns noop
Sending Access-Accept of id 71 to xx.xx.xx.xx port 32772
  Idle-Timeout := 3600 [from radgroupreply]
  Colubris-AVPair += "one-to-one-nat=1" [from radgroupreply]
  Colubris-AVPair += "smtp-redirect=xx.xx.xx.xx" [from radgroupreply]
  MS-CHAP2-Success =
0x47533d46453336353138333746413938383539443430424143443130383539364131454434363631384642
  MS-MPPE-Recv-Key = 0x200ce521f54129a00b8ddbfa0d38a1df
  MS-MPPE-Send-Key = 0x64debbade6a03f53df884e7ef78a7645
  MS-MPPE-Encryption-Policy = 0x00000001
  MS-MPPE-Encryption-Types = 0x00000006