Strange rlm_sql usage problem

Franco Gasperino francog at velocityinet.com
Sun Mar 19 00:07:59 CET 2006


Hello list,

  I've run into an issue with freeradius that i cannot seem to solve. When a 
request arrives from our as5800, the radius server correctly uses the rlm_sql 
module to lookup user check items. The user is authenticated, but incomplete 
reply items are sent back to the as5800.

  I've added a few DEBUG() calls into the rlm_sql module (sql.c and rlm_sql.c) 
to dump the raw SQL_ROW values to console. It looks like only partial result 
sets are being received by the module.

  radcheck queried, correct results.
  radreply queried, no results at all
  radgroupcheck queried, partial results
  radgroupreply queried, partial results.

  You may compare the freeradius debug output on the pair lists vs the manual 
queries below. I've cut out the authentication queries, and have labeled the 
added debugging output lines as with a CUSTOM: tag. Once again the only 
modifications to the source are DEBUG() statements to view data, and these 
were added after the issue occurred.

  Look the check/reply items from the radius debug, and compare them to the 
same queries manually entered in psql below.

  This has me stumped at the moment. Any pointers would be greatly 
appreciated.

Versions:
  freeradius 1.1.0 (with the amd64 dictionary patch from CVS)
  postgresql 8.1.2

--- BEGIN freeradius -X output ---

Starting - reading configuration files ...
reread_config:  reading radiusd.conf
Config:   including file: /etc/freeradius/proxy.conf
Config:   including file: /etc/freeradius/clients.conf
Config:   including file: /etc/freeradius/snmp.conf
Config:   including file: /etc/freeradius/eap.conf
Config:   including file: /etc/freeradius/sql.conf
 main: prefix = "/usr"
 main: localstatedir = "/var"
 main: logdir = "/var/log/freeradius"
 main: libdir = "/usr/lib/freeradius"
 main: radacctdir = "/var/log/freeradius/radacct"
 main: hostname_lookups = no
 main: snmp = no
 main: max_request_time = 30
 main: cleanup_delay = 5
 main: max_requests = 1024
 main: delete_blocked_requests = 0
 main: port = 1812
 main: allow_core_dumps = no
 main: log_stripped_names = no
 main: log_file = "/var/log/freeradius/radius.log"
 main: log_auth = yes
 main: log_auth_badpass = yes
 main: log_auth_goodpass = no
 main: pidfile = "/var/run/freeradius/freeradius.pid"
 main: user = "freerad"
 main: group = "freerad"
 main: usercollide = no
 main: lower_user = "no"
 main: lower_pass = "no"
 main: nospace_user = "no"
 main: nospace_pass = "no"
 main: checkrad = "/usr/sbin/checkrad"
 main: proxy_requests = no
 proxy: retry_delay = 5
 proxy: retry_count = 3
 proxy: synchronous = no
 proxy: default_fallback = yes
 proxy: dead_time = 120
 proxy: post_proxy_authorize = no
 proxy: wake_all_if_all_dead = no
 security: max_attributes = 200
 security: reject_delay = 1
 security: status_server = no
 main: debug_level = 0
read_config_files:  reading dictionary
read_config_files:  reading naslist
Using deprecated naslist file.  Support for this will go away soon.
read_config_files:  reading clients
read_config_files:  reading realms
 listen: ipaddr = 10.0.50.10 IP address [10.0.50.10]
 listen: port = 1812
 listen: type = "auth"
radiusd:  entering modules setup
Module: Library search path is /usr/lib/freeradius
Module: Loaded exec
 exec: wait = yes
 exec: program = "(null)"
 exec: input_pairs = "request"
 exec: output_pairs = "(null)"
 exec: packet_type = "(null)"
rlm_exec: Wait=yes but no output defined. Did you mean output=none?
Module: Instantiated exec (exec)
Module: Loaded expr
Module: Instantiated expr (expr)
Module: Loaded PAP
 pap: encryption_scheme = "crypt"
Module: Instantiated pap (pap)
Module: Loaded CHAP
Module: Instantiated chap (chap)
Module: Loaded preprocess
 preprocess: huntgroups = "/etc/freeradius/huntgroups"
 preprocess: hints = "/etc/freeradius/hints"
 preprocess: with_ascend_hack = no
 preprocess: ascend_channels_per_line = 23
 preprocess: with_ntdomain_hack = no
 preprocess: with_specialix_jetstream_hack = no
 preprocess: with_cisco_vsa_hack = yes
Module: Instantiated preprocess (preprocess)
Module: Loaded SQL
 sql: driver = "rlm_sql_postgresql"
 sql: server = "10.0.50.60"
 sql: port = "5432"
 sql: login = "XXXX"
 sql: password = "XXXX"
 sql: radius_db = "XXXX"
 sql: acct_table = "radacct"
 sql: acct_table2 = "service_radius_accounting"
 sql: authcheck_table = "service_radius_radcheck_dialup"
 sql: authreply_table = "service_radius_radreply_dialup"
 sql: groupcheck_table = "service_radius_radgroupcheck_dialup"
 sql: groupreply_table = "service_radius_radgroupreply_dialup"
 sql: usergroup_table = "service_radius_usergroup_dialup"
 sql: nas_table = "nas"
 sql: dict_table = "dictionary"
 sql: sqltrace = yes
 sql: sqltracefile = "/var/log/freeradius/sqltrace.sql"
 sql: readclients = no
 sql: deletestalesessions = yes
 sql: num_sql_socks = 5
 sql: sql_user_name = "%{Stripped-User-Name:-%{User-Name:-none}}"
 sql: default_user_profile = ""
 sql: query_on_not_found = no
 sql: authorize_check_query = " ?  SELECT ?    id, ?    username, ?    
attribute, ?    value, ?    op ?  FROM ?    service_radius_radcheck_dialup ?  
WHERE ?    username = '%{SQL-User-Name}' ?  ORDER BY ?    id ?"
 sql: authorize_reply_query = " ?  SELECT ?    id, ?    username, ?    
attribute, ?    value, ?    op ?  FROM ?    service_radius_radreply_dialup ?  
WHERE ?    username = '%{SQL-User-Name}' ?  ORDER BY ?    id ?"
 sql: authorize_group_check_query = " ?  SELECT DISTINCT ?    
service_radius_radgroupcheck_dialup.id, ?    
service_radius_radgroupcheck_dialup.groupname, ?    
service_radius_radgroupcheck_dialup.attribute, ?    
service_radius_radgroupcheck_dialup.value,?    
service_radius_radgroupcheck_dialup.op ?  FROM ?    
service_radius_radgroupcheck_dialup, ?    service_radius_usergroup_dialup ?  
WHERE ?    service_radius_usergroup_dialup.username = '%{SQL-User-Name}' ?  
AND ?    service_radius_usergroup_dialup.groupname = 
service_radius_radgroupcheck_dialup.groupname ?  ORDER BY ?    
service_radius_radgroupcheck_dialup.id ?"
 sql: authorize_group_reply_query = " ?  SELECT DISTINCT ?    
service_radius_radgroupreply_dialup.id, ?    
service_radius_radgroupreply_dialup.groupname, ?    
service_radius_radgroupreply_dialup.attribute, ?    
service_radius_radgroupreply_dialup.value, ?    
service_radius_radgroupreply_dialup.op ?  FROM ?    
service_radius_radgroupreply_dialup,?    service_radius_usergroup_dialup ?  
WHERE ?    service_radius_usergroup_dialup.username = '%{SQL-User-Name}' ?  
AND ?    service_radius_usergroup_dialup.groupname = 
service_radius_radgroupreply_dialup.groupname ?  ORDER BY ?    
service_radius_radgroupreply_dialup.id ?"

  *** ACCOUNTING QUERIES CUT - NO NEED FOR SPAM HERE ***

 sql: connect_failure_retry_delay = 60
 sql: simul_verify_query = ""
 sql: postauth_table = "radpostauth"
 sql: postauth_query = ""
 sql: safe-characters = 
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
rlm_sql (sql): Driver rlm_sql_postgresql (module rlm_sql_postgresql) loaded 
and linked
rlm_sql (sql): Attempting to connect to XXXX at 10.0.50.60:5432/XXXX
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_postgresql #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_postgresql #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_postgresql #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_postgresql #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_postgresql #4
rlm_sql (sql): Connected new DB handle, #4
Module: Instantiated sql (sql)
Module: Loaded Acct-Unique-Session-Id
 acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, 
Client-IP-Address, NAS-Port"
Module: Instantiated acct_unique (acct_unique)
Module: Loaded detail
 detail: detailfile = 
"/var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d"
 detail: detailperm = 384
 detail: dirperm = 493
 detail: locking = no
Module: Instantiated detail (reply_log)
Listening on authentication 10.0.50.10:1812
Ready to process requests.

rad_recv: Access-Request packet from host 10.0.50.254:1645, id=79, length=147
        Framed-Protocol = PPP
        User-Name = "francog at velocityinet.com"
        User-Password = "mypassword"
        Calling-Station-Id = "XXXX"
        Called-Station-Id = "XXXX"
        NAS-Port = 1043
        NAS-Port-Type = Async
        Connect-Info = "48000/26400 V90/V42bis/LAPM"
        Service-Type = Framed-User
        NAS-IP-Address = 10.0.50.254
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 0
  modcall[authorize]: module "preprocess" returns ok for request 0
  modcall[authorize]: module "chap" returns noop for request 0
radius_xlat:  'francog at velocityinet.com'
rlm_sql (sql): sql_set_user escaped user --> 'francog at velocityinet.com'
radius_xlat:  ' ?  SELECT ?    id, ?    username, ?    attribute, ?    
value, ?    op ?  FROM ?    service_radius_radcheck_dialup ?  WHERE ?    
username = 'francog at velocityinet.com' ?  ORDER BY ?    id ?'
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql_postgresql: query:  ?  SELECT ?    id, ?    username, ?    
attribute, ?    value, ?    op ?  FROM ?    service_radius_radcheck_dialup ?  
WHERE ?    username = 'francog at velocityinet.com' ?  ORDER BY ?    id ?
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: affected rows =

CUSTOM: Id: 49, Username/Groupname: francog at velocityinet.com, Attribute: 
User-Password, Value: mypassword, Operator: ==

CUSTOM: rlm_sql:  check items (radcheck)
     User-Password == "mypassword"

radius_xlat:  ' ?  SELECT DISTINCT ?    
service_radius_radgroupcheck_dialup.id, ?    
service_radius_radgroupcheck_dialup.groupname, ?    
service_radius_radgroupcheck_dialup.attribute, ?    
service_radius_radgroupcheck_dialup.value,?    
service_radius_radgroupcheck_dialup.op ?  FROM ?    
service_radius_radgroupcheck_dialup, ?    service_radius_usergroup_dialup ?  
WHERE ?    service_radius_usergroup_dialup.username = 
'francog at velocityinet.com' ?  AND ?    
service_radius_usergroup_dialup.groupname = 
service_radius_radgroupcheck_dialup.groupname ?  ORDER BY ?    
service_radius_radgroupcheck_dialup.id ?'
rlm_sql_postgresql: query:  ?  SELECT DISTINCT ?    
service_radius_radgroupcheck_dialup.id, ?    
service_radius_radgroupcheck_dialup.groupname, ?    
service_radius_radgroupcheck_dialup.attribute, ?    
service_radius_radgroupcheck_dialup.value,?    
service_radius_radgroupcheck_dialup.op ?  FROM ?    
service_radius_radgroupcheck_dialup, ?    service_radius_usergroup_dialup ?  
WHERE ?    service_radius_usergroup_dialup.username = 
'francog at velocityinet.com' ?  AND ?    
service_radius_usergroup_dialup.groupname = 
service_radius_radgroupcheck_dialup.groupname ?  ORDER BY ?    
service_radius_radgroupcheck_dialup.id ?
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: affected rows =

CUSTOM: Id: 14, Username/Groupname: Standard Dial-Up Service, Attribute: 
Service-Type, Value: Framed-User, Operator: ==
CUSTOM: Id: 43, Username/Groupname: Standard Dial-Up Service, Attribute: 
Auth-Type, Value: Local, Operator: :=

CUSTOM: rlm_sql:  check items (radcheck+radgroupcheck)
     User-Password == "mypassword"
     Service-Type == Framed-User
     Auth-Type := Local

radius_xlat:  ' ?  SELECT ?    id, ?    username, ?    attribute, ?    
value, ?    op ?  FROM ?    service_radius_radreply_dialup ?  WHERE ?    
username = 'francog at velocityinet.com' ?  ORDER BY ?    id ?'
rlm_sql_postgresql: query:  ?  SELECT ?    id, ?    username, ?    
attribute, ?    value, ?    op ?  FROM ?    service_radius_radreply_dialup ?  
WHERE ?    username = 'francog at velocityinet.com' ?  ORDER BY ?    id ?
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: affected rows =
rlm_sql:  reply items (radreply)
radius_xlat:  ' ?  SELECT DISTINCT ?    
service_radius_radgroupreply_dialup.id, ?    
service_radius_radgroupreply_dialup.groupname, ?    
service_radius_radgroupreply_dialup.attribute, ?    
service_radius_radgroupreply_dialup.value, ?    
service_radius_radgroupreply_dialup.op ?  FROM ?    
service_radius_radgroupreply_dialup,?    service_radius_usergroup_dialup ?  
WHERE ?    service_radius_usergroup_dialup.username = 
'francog at velocityinet.com' ?  AND ?    
service_radius_usergroup_dialup.groupname = 
service_radius_radgroupreply_dialup.groupname ?  ORDER BY ?    
service_radius_radgroupreply_dialup.id ?'
rlm_sql_postgresql: query:  ?  SELECT DISTINCT ?    
service_radius_radgroupreply_dialup.id, ?    
service_radius_radgroupreply_dialup.groupname, ?    
service_radius_radgroupreply_dialup.attribute, ?    
service_radius_radgroupreply_dialup.value, ?    
service_radius_radgroupreply_dialup.op ?  FROM ?    
service_radius_radgroupreply_dialup,?    service_radius_usergroup_dialup ?  
WHERE ?    service_radius_usergroup_dialup.username = 
'francog at velocityinet.com' ?  AND ?    
service_radius_usergroup_dialup.groupname = 
service_radius_radgroupreply_dialup.groupname ?  ORDER BY ?    
service_radius_radgroupreply_dialup.id ?
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: affected rows =

CUSTOM: Id: 18, Username/Groupname: Standard Dial-Up Service, Attribute: 
Port-Limit, Value: 1, Operator: =
CUSTOM: Id: 19, Username/Groupname: Standard Dial-Up Service, Attribute: 
Session-Timeout, Value: 21600, Operator: =
CUSTOM: Id: 20, Username/Groupname: Standard Dial-Up Service, Attribute: 
Idle-Timeout, Value: 600, Operator: =

CUSTOM: rlm_sql:  reply items (radreply+radgroupreply)
     Port-Limit = 1
     Session-Timeout = 21600
     Idle-Timeout = 600

rlm_sql (sql): Released sql socket id: 4
rlm_sql:  check items
     User-Password == "mypassword"
     Service-Type == Framed-User
     Auth-Type := Local
rlm_sql:  reply items
     Port-Limit = 1
     Session-Timeout = 21600
     Idle-Timeout = 600
  modcall[authorize]: module "sql" returns ok for request 0
modcall: leaving group authorize (returns ok) for request 0
  rad_check_password:  Found Auth-Type Local
auth: type Local
auth: user supplied User-Password matches local User-Password
Login OK: [francog at velocityinet.com] (from client access-dialup-1 port 1043 
cli 5094485658)
  Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 0
radius_xlat:  '/var/log/freeradius/radacct/10.0.50.254/reply-detail-20060317'
rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d 
expands to /var/log/freeradius/radacct/10.0.50.254/reply-detail-20060317
  modcall[post-auth]: module "reply_log" returns ok for request 0
modcall: leaving group post-auth (returns ok) for request 0
Sending Access-Accept of id 79 to 10.0.50.254 port 1645
        Port-Limit = 1
        Session-Timeout = 21600
        Idle-Timeout = 600
Finished request 0
Going to the next request
--- Walking the entire request list ---

--- END ---

--- BEGIN sql.conf content ---

sql {
        driver = "rlm_sql_postgresql"

        server = "10.0.50.60"
        port = 5432
        login = "XXXX"
        password = "XXXX"

        radius_db = "XXXX"

        acct_table1 = "service_radius_accounting"
        acct_table2 = "service_radius_accounting"
        authcheck_table = "service_radius_radcheck_dialup"
        authreply_table = "service_radius_radreply_dialup"
        groupcheck_table = "service_radius_radgroupcheck_dialup"
        groupreply_table = "service_radius_radgroupreply_dialup"
        usergroup_table = "service_radius_usergroup_dialup"

        deletestalesessions = yes

        sqltrace = yes
        sqltracefile = ${logdir}/sqltrace.sql

        num_sql_socks = 5

        sql_user_name = "%{Stripped-User-Name:-%{User-Name:-none}}"

        authorize_check_query = " \
          SELECT \
            id, \
            username, \
            attribute, \
            value, \
            op \
          FROM \
            ${authcheck_table} \
          WHERE \
            username = '%{SQL-User-Name}' \
          ORDER BY \
            id \
        "
        authorize_reply_query = " \
          SELECT \
            id, \
            username, \
            attribute, \
            value, \
            op \
          FROM \
            ${authreply_table} \
          WHERE \
            username = '%{SQL-User-Name}' \
          ORDER BY \
            id \
        "
        authorize_group_check_query = " \
          SELECT DISTINCT \
            ${groupcheck_table}.id, \
            ${groupcheck_table}.groupname, \
            ${groupcheck_table}.attribute, \
            ${groupcheck_table}.value,\
            ${groupcheck_table}.op \
          FROM \
            ${groupcheck_table}, \
            ${usergroup_table} \
          WHERE \
            ${usergroup_table}.username = '%{SQL-User-Name}' \
          AND \
            ${usergroup_table}.groupname = ${groupcheck_table}.groupname \
          ORDER BY \
            ${groupcheck_table}.id \
        "
        authorize_group_reply_query = " \
          SELECT DISTINCT \
            ${groupreply_table}.id, \
            ${groupreply_table}.groupname, \
            ${groupreply_table}.attribute, \
            ${groupreply_table}.value, \
            ${groupreply_table}.op \
          FROM \
            ${groupreply_table},\
            ${usergroup_table} \
          WHERE \
            ${usergroup_table}.username = '%{SQL-User-Name}' \
          AND \
            ${usergroup_table}.groupname = ${groupreply_table}.groupname \
          ORDER BY \

        group_membership_query = " \
          SELECT \
            groupname \
          FROM \
            ${usergroup_table} \
          WHERE \
            username='%{SQL-User-Name}' \
          "         
--- END ---

--- BEGIN manual postgresql queries ---

velocity=> select * from service_radius_radcheck_dialup where username = 
'francog at velocityinet.com';
 id |         username         |   attribute   | op |   value
----+--------------------------+---------------+----+------------
 22 | francog at velocityinet.com | User-Password | == | mypassword
(1 row)

velocity=> select * from service_radius_radreply_dialup where username = 
'francog at velocityinet.com';
 id |         username         |  attribute   | op |        value
----+--------------------------+--------------+----+---------------------
 46 | francog at velocityinet.com | Port-Limit   | =  | 2
 48 | francog at velocityinet.com | Cisco-AVPair | := | ip:addr-pool=active
(2 rows)

velocity=> select * from service_radius_usergroup_dialup where username = 
'francog at velocityinet.com';
 id |         username         |        groupname
----+--------------------------+--------------------------
  0 | francog at velocityinet.com | Standard Dial-Up Service
(1 row)

velocity=> select * from service_radius_radgroupcheck_dialup where groupname = 
'Standard Dial-Up Service';
 id |        groupname         |    attribute     | op |    value
----+--------------------------+------------------+----+-------------
 12 | Standard Dial-Up Service | Simultaneous-Use | := | 1
 43 | Standard Dial-Up Service | Auth-Type        | := | Local
 14 | Standard Dial-Up Service | Service-Type     | == | Framed-User
(3 rows)

velocity=> select * from service_radius_radgroupreply_dialup where groupname = 
'Standard Dial-Up Service';
 id |        groupname         |     attribute      | op |        value
----+--------------------------+--------------------+----+---------------------
 15 | Standard Dial-Up Service | Framed-Protocol    | =  | PPP
 17 | Standard Dial-Up Service | Framed-MTU         | =  | 1500
 18 | Standard Dial-Up Service | Port-Limit         | =  | 1
 19 | Standard Dial-Up Service | Session-Timeout    | =  | 21600
 20 | Standard Dial-Up Service | Idle-Timeout       | =  | 600
 16 | Standard Dial-Up Service | Framed-Compression | =  | Van-Jacobson-TCP-IP
(6 rows)

--- END ---

-- 

Franco Gasperino



More information about the Freeradius-Users mailing list