Framed-IP-Address into Access-Request is not processed

20 Jun 2017

      Hello Freeradius community,

I'm trying configure FreeRadius (v2.2.6) + sql module for users + sqlippool
module to provide an IP address which the NAS client has suggested. The
suggested IP address only should be provided if it matches in the pool
allocated for this user, in any other case, the server could answer other
allowed IP from the selected pool. The client is sending the
"Framed-IP-Address" field in the Access-Request message but FreeRadius
ignores it.

I'm basing this philosophy in the RFC2865, section 5.8, Framed-IP-Address:

      "It MAY be used in Access-Request packet as a hint by the NAS to the
server that would prefer that address, but the server is not required to
the hint."

Probably this feature is not supported but I want to be sure before develop
my own workaround. I wonder if I could get it using unlang code.

A FreeRadius upgrade is not allowed by now but I would be interesting to
know if this feature could be achieve in other version.

Thank you in advance.

PD: The radius -X log trace is as follows:

radiusd -X
radiusd: FreeRADIUS Version 2.2.6, for host x86_64-redhat-linux-gnu, built
on Sep 10 2015 at 07:12:21
Copyright (C) 1999-2013 The FreeRADIUS server project and contributors.
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
PARTICULAR PURPOSE.
You may redistribute copies of FreeRADIUS under the terms of the
GNU General Public License.
For more information about these matters, see the file named COPYRIGHT.
Starting - reading configuration files ...
including configuration file /etc/raddb/radiusd.conf
including configuration file /etc/raddb/proxy.conf
including configuration file /etc/raddb/clients.conf
including files in directory /etc/raddb/modules/
including configuration file /etc/raddb/modules/dynamic_clients
including configuration file /etc/raddb/modules/sradutmp
including configuration file /etc/raddb/modules/soh
including configuration file /etc/raddb/modules/echo
including configuration file /etc/raddb/modules/mac2vlan
including configuration file /etc/raddb/modules/detail
including configuration file /etc/raddb/modules/unix
including configuration file /etc/raddb/modules/expiration
including configuration file /etc/raddb/modules/always
including configuration file /etc/raddb/modules/pam
including configuration file /etc/raddb/modules/linelog
including configuration file /etc/raddb/modules/inner-eap
including configuration file /etc/raddb/modules/radutmp
including configuration file /etc/raddb/modules/attr_rewrite
including configuration file /etc/raddb/modules/smbpasswd
including configuration file /etc/raddb/modules/ntlm_auth
including configuration file /etc/raddb/modules/detail.example.com
including configuration file /etc/raddb/modules/expr
including configuration file /etc/raddb/modules/policy
including configuration file /etc/raddb/modules/perl
including configuration file /etc/raddb/modules/realm
including configuration file /etc/raddb/modules/rediswho
including configuration file /etc/raddb/modules/checkval
including configuration file /etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /etc/raddb/modules/logintime
including configuration file /etc/raddb/modules/exec
including configuration file /etc/raddb/modules/preprocess
including configuration file /etc/raddb/modules/detail.log
including configuration file /etc/raddb/modules/cache
including configuration file /etc/raddb/modules/etc_group
including configuration file /etc/raddb/modules/digest
including configuration file /etc/raddb/modules/chap
including configuration file /etc/raddb/modules/pap
including configuration file /etc/raddb/modules/redis
including configuration file /etc/raddb/modules/opendirectory
including configuration file /etc/raddb/modules/acct_unique
including configuration file /etc/raddb/modules/counter
including configuration file /etc/raddb/modules/files
including configuration file /etc/raddb/modules/otp
including configuration file /etc/raddb/modules/attr_filter
including configuration file /etc/raddb/modules/mschap
including configuration file /etc/raddb/modules/passwd
including configuration file /etc/raddb/modules/dhcp_sqlippool
including configuration file /etc/raddb/modules/cui
including configuration file /etc/raddb/modules/ippool
including configuration file /etc/raddb/modules/replicate
including configuration file /etc/raddb/modules/mac2ip
including configuration file /etc/raddb/modules/wimax
including configuration file /etc/raddb/modules/radrelay
including configuration file /etc/raddb/modules/sql_log
including configuration file /etc/raddb/modules/smsotp
including configuration file /etc/raddb/eap.conf
including configuration file /etc/raddb/sql.conf
including configuration file /etc/raddb/sql/mysql/dialup.conf
including configuration file /etc/raddb/sqlippool.conf
including configuration file /etc/raddb/sql/mysql/ippool.conf
including configuration file /etc/raddb/policy.conf
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/default
main {
        user = "radiusd"
        group = "radiusd"
        allow_core_dumps = no
}
including dictionary file /etc/raddb/dictionary
main {
        name = "radiusd"
        prefix = "/usr"
        localstatedir = "/var"
        sbindir = "/usr/sbin"
        logdir = "/var/log/radius"
        run_dir = "/var/run/radiusd"
        libdir = "/usr/lib64/freeradius"
        radacctdir = "/var/log/radius/radacct"
        hostname_lookups = no
        max_request_time = 5
        cleanup_delay = 5
        max_requests = 1024
        pidfile = "/var/run/radiusd/radiusd.pid"
        checkrad = "/usr/sbin/checkrad"
        debug_level = 0
        proxy_requests = yes
 log {
        stripped_names = no
        auth = no
        auth_badpass = no
        auth_goodpass = no
 }
 security {
        max_attributes = 200
        reject_delay = 1
        status_server = yes
 }
}
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
        retry_delay = 5
        retry_count = 3
        default_fallback = no
        dead_time = 120
        wake_all_if_all_dead = no
 }
 home_server localhost {
        ipaddr = 127.0.0.1
        port = 1812
        type = "auth"
        secret = "testing123"
        response_window = 20.000000
        response_timeouts = 1
        max_outstanding = 65536
        require_message_authenticator = yes
        zombie_period = 40
        status_check = "status-server"
        ping_interval = 30
        check_interval = 30
        num_answers_to_alive = 3
        num_pings_to_alive = 3
        revive_interval = 120
        status_check_timeout = 4
  coa {
        irt = 2
        mrt = 16
        mrc = 5
        mrd = 30
  }
 }
 home_server_pool my_auth_failover {
        type = fail-over
        home_server = localhost
 }
 realm example.com {
        auth_pool = my_auth_failover
 }
 realm LOCAL {
 }
radiusd: #### Loading Clients ####
 client localhost {
        ipaddr = 127.0.0.1
        require_message_authenticator = no
        secret = "mysecret"
        nastype = "other"
 }
radiusd: #### Instantiating modules ####
 instantiate {
 Module: Linked to module rlm_exec
 Module: Instantiating module "exec" from file /etc/raddb/modules/exec
  exec {
        wait = no
        input_pairs = "request"
        shell_escape = yes
        timeout = 10
  }
 Module: Linked to module rlm_expr
 Module: Instantiating module "expr" from file /etc/raddb/modules/expr
 Module: Linked to module rlm_expiration
 Module: Instantiating module "expiration" from file
/etc/raddb/modules/expiration
  expiration {
        reply-message = "Password Has Expired  "
  }
 Module: Linked to module rlm_logintime
 Module: Instantiating module "logintime" from file
/etc/raddb/modules/logintime
  logintime {
        reply-message = "You are calling outside your allowed timespan  "
        minimum-timeout = 60
  }
 }
radiusd: #### Loading Virtual Servers ####
server { # from file
 modules {
  Module: Creating Post-Auth-Type = REJECT
 Module: Checking authorize {...} for more modules to load
 Module: Linked to module rlm_preprocess
 Module: Instantiating module "preprocess" from file
/etc/raddb/modules/preprocess
  preprocess {
        huntgroups = "/etc/raddb/huntgroups"
        hints = "/etc/raddb/hints"
        with_ascend_hack = no
        ascend_channels_per_line = 23
        with_ntdomain_hack = no
        with_specialix_jetstream_hack = no
        with_cisco_vsa_hack = no
        with_alvarion_vsa_hack = no
  }
reading pairlist file /etc/raddb/huntgroups
reading pairlist file /etc/raddb/hints
 Module: Linked to module rlm_files
 Module: Instantiating module "files" from file /etc/raddb/modules/files
  files {
        usersfile = "/etc/raddb/users"
        acctusersfile = "/etc/raddb/acct_users"
        preproxy_usersfile = "/etc/raddb/preproxy_users"
        compat = "no"
  }
reading pairlist file /etc/raddb/users
reading pairlist file /etc/raddb/acct_users
reading pairlist file /etc/raddb/preproxy_users
 Module: Linked to module rlm_sql
 Module: Instantiating module "sql" from file /etc/raddb/sql.conf
  sql {
        driver = "rlm_sql_mysql"
        server = "se3-PGW"
        port = "3306"
        login = "radius"
        password = "mypass"
        radius_db = "MY_DB"
        read_groups = yes
        sqltrace = no
        sqltracefile = "/var/log/radius/sqltrace.sql"
        readclients = no
        deletestalesessions = yes
        num_sql_socks = 32
        lifetime = 0
        max_queries = 0
        sql_user_name = "%{User-Name}"
        default_user_profile = ""
        nas_query = "SELECT id, nasname, shortname, type, secret, server
FROM nas"
        authorize_check_query = "SELECT id, username, attribute, value, op
          FROM radcheck           WHERE username = '%{SQL-User-Name}'
    ORDER BY id"
        authorize_reply_query = "SELECT id, username, attribute, value, op
          FROM radreply           WHERE username = '%{SQL-User-Name}'
    ORDER BY id"
        authorize_group_check_query = "SELECT id, groupname, attribute,
      Value, op           FROM radgroupcheck           WHERE groupname =
'%{Sql-Group}'           ORDER BY id"
        authorize_group_reply_query = "SELECT id, groupname, attribute,
      value, op           FROM radgroupreply           WHERE groupname =
'%{Sql-Group}'           ORDER BY id"
        accounting_onoff_query = "          UPDATE radacct           SET
           acctstoptime       =  '%S',              acctsessiontime    =
 unix_timestamp('%S') -
 unix_timestamp(acctstarttime),              acctterminatecause =
 '%{Acct-Terminate-Cause}',              acctstopdelay      =
 %{%{Acct-Delay-Time}:-0}           WHERE acctstoptime IS NULL
AND nasipaddress      =  '%{NAS-IP-Address}'           AND acctstarttime
  <= '%S'"
        accounting_update_query = "           UPDATE radacct           SET
             framedipaddress = '%{Framed-IP-Address}',
 acctsessiontime     = '%{%{Acct-Session-Time}:-0}',
 acctinputoctets     = '%{%{Acct-Input-Gigawords}:-0}'  << 32 |
                       '%{%{Acct-Input-Octets}:-0}',
 acctoutputoctets    = '%{%{Acct-Output-Gigawords}:-0}' << 32 |
                       '%{%{Acct-Output-Octets}:-0}'           WHERE
acctsessionid = '%{Acct-Session-Id}'           AND username        =
'%{SQL-User-Name}'           AND nasipaddress    = '%{NAS-IP-Address}'"
        accounting_update_query_alt = "           INSERT INTO radacct
      (acctsessionid,    acctuniqueid,      username,              realm,
         nasipaddress,      nasportid,              nasporttype,
 acctstarttime,     acctsessiontime,              acctauthentic,
 connectinfo_start, acctinputoctets,              acctoutputoctets,
calledstationid,   callingstationid,              servicetype,
 framedprotocol,    framedipaddress,              acctstartdelay,
xascendsessionsvrkey)           VALUES             ('%{Acct-Session-Id}',
'%{Acct-Unique-Session-Id}',              '%{SQL-User-Name}',
 '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',
 '%{NAS-Port-Type}',              DATE_SUB('%S',
INTERVAL (%{%{Acct-Session-Time}:-0} +
%{%{Acct-Delay-Time}:-0}) SECOND),
'%{%{Acct-Session-Time}:-0}',              '%{Acct-Authentic}', '',
     '%{%{Acct-Input-Gigawords}:-0}' << 32 |
 '%{%{Acct-Input-Octets}:-0}',              '%{%{Acct-Output-Gigawords}:-0}'
<< 32 |              '%{%{Acct-Output-Octets}:-0}',
 '%{Called-Station-Id}', '%{Calling-Station-Id}',
 '%{Service-Type}', '%{Framed-Protocol}',
 '%{Framed-IP-Address}',              '0', '%{X-Ascend-Session-Svr-Key}')"
        accounting_start_query = "           INSERT INTO radacct
  (acctsessionid,    acctuniqueid,     username,              realm,
     nasipaddress,     nasportid,              nasporttype,
 acctstarttime,    acctstoptime,              acctsessiontime,
 acctauthentic,    connectinfo_start,              connectinfo_stop,
acctinputoctets,  acctoutputoctets,              calledstationid,
 callingstationid, acctterminatecause,              servicetype,
 framedprotocol,   framedipaddress,              acctstartdelay,
acctstopdelay,    xascendsessionsvrkey)           VALUES
('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
 '%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}',
'%{NAS-Port}',              '%{NAS-Port-Type}', '%S', NULL,
 '0', '%{Acct-Authentic}', '%{Connect-Info}',              '', '0', '0',
           '%{Called-Station-Id}', '%{Calling-Station-Id}', '',
 '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',
   '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')"
        accounting_start_query_alt = "           UPDATE radacct SET
     acctstarttime     = '%S',              acctstartdelay    =
'%{%{Acct-Delay-Time}:-0}',              connectinfo_start =
'%{Connect-Info}'           WHERE acctsessionid  = '%{Acct-Session-Id}'
      AND username         = '%{SQL-User-Name}'           AND nasipaddress
    = '%{NAS-IP-Address}'"
        accounting_stop_query = "           UPDATE radacct SET
 acctstoptime       = '%S',              acctsessiontime    =
'%{%{Acct-Session-Time}:-0}',              acctinputoctets    =
'%{%{Acct-Input-Gigawords}:-0}' << 32 |
'%{%{Acct-Input-Octets}:-0}',              acctoutputoctets   =
'%{%{Acct-Output-Gigawords}:-0}' << 32 |
'%{%{Acct-Output-Octets}:-0}',              acctterminatecause =
'%{Acct-Terminate-Cause}',              acctstopdelay      =
'%{%{Acct-Delay-Time}:-0}',              connectinfo_stop   =
'%{Connect-Info}'           WHERE acctsessionid   = '%{Acct-Session-Id}'
        AND username          = '%{SQL-User-Name}'           AND
nasipaddress      = '%{NAS-IP-Address}'"
        accounting_stop_query_alt = "           INSERT INTO radacct
    (acctsessionid, acctuniqueid, username,              realm,
nasipaddress, nasportid,              nasporttype, acctstarttime,
acctstoptime,              acctsessiontime, acctauthentic,
connectinfo_start,              connectinfo_stop, acctinputoctets,
acctoutputoctets,              calledstationid, callingstationid,
acctterminatecause,              servicetype, framedprotocol,
framedipaddress,              acctstartdelay, acctstopdelay)
VALUES             ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
         '%{SQL-User-Name}',              '%{Realm}', '%{NAS-IP-Address}',
'%{NAS-Port}',              '%{NAS-Port-Type}',              DATE_SUB('%S',
                 INTERVAL (%{%{Acct-Session-Time}:-0} +
 %{%{Acct-Delay-Time}:-0}) SECOND),              '%S',
'%{%{Acct-Session-Time}:-0}', '%{Acct-Authentic}', '',
 '%{Connect-Info}',              '%{%{Acct-Input-Gigawords}:-0}' << 32 |
           '%{%{Acct-Input-Octets}:-0}',
 '%{%{Acct-Output-Gigawords}:-0}' << 32 |
 '%{%{Acct-Output-Octets}:-0}',              '%{Called-Station-Id}',
'%{Calling-Station-Id}',              '%{Acct-Terminate-Cause}',
   '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',
     '0', '%{%{Acct-Delay-Time}:-0}')"
        group_membership_query = "SELECT groupname           FROM
radusergroup           WHERE username = '%{SQL-User-Name}'           ORDER
BY priority"
        connect_failure_retry_delay = 60
        simul_count_query = ""
        simul_verify_query = "SELECT radacctid, acctsessionid, username,
                             nasipaddress, nasportid, framedipaddress,
                           callingstationid, framedprotocol
               FROM radacct                                WHERE username =
'%{SQL-User-Name}'                                AND acctstoptime IS NULL"
        postauth_query = "INSERT INTO radpostauth
(username, pass, reply, authdate)                           VALUES (
                    '%{User-Name}',
'%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S')"
        safe-characters = "@abcdefghijklmnopqrstuvwxyzABCD
EFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked
rlm_sql (sql): Attempting to connect to radius@se3-PGW:3306/DB_BICS
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_mysql #0
rlm_sql_mysql: Starting connect to MySQL server for #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql (sql): starting 1
rlm_sql (sql): Attempting to connect rlm_sql_mysql #1
rlm_sql_mysql: Starting connect to MySQL server for #1
rlm_sql (sql): Connected new DB handle, #1
rlm_sql (sql): starting 2
rlm_sql (sql): Attempting to connect rlm_sql_mysql #2
rlm_sql_mysql: Starting connect to MySQL server for #2
rlm_sql (sql): Connected new DB handle, #2
rlm_sql (sql): starting 3
rlm_sql (sql): Attempting to connect rlm_sql_mysql #3
rlm_sql_mysql: Starting connect to MySQL server for #3
rlm_sql (sql): Connected new DB handle, #3
rlm_sql (sql): starting 4
rlm_sql (sql): Attempting to connect rlm_sql_mysql #4
rlm_sql_mysql: Starting connect to MySQL server for #4
rlm_sql (sql): Connected new DB handle, #4
rlm_sql (sql): starting 5
rlm_sql (sql): Attempting to connect rlm_sql_mysql #5
rlm_sql_mysql: Starting connect to MySQL server for #5
rlm_sql (sql): Connected new DB handle, #5
rlm_sql (sql): starting 6
rlm_sql (sql): Attempting to connect rlm_sql_mysql #6
rlm_sql_mysql: Starting connect to MySQL server for #6
rlm_sql (sql): Connected new DB handle, #6
rlm_sql (sql): starting 7
rlm_sql (sql): Attempting to connect rlm_sql_mysql #7
rlm_sql_mysql: Starting connect to MySQL server for #7
rlm_sql (sql): Connected new DB handle, #7
rlm_sql (sql): starting 8
rlm_sql (sql): Attempting to connect rlm_sql_mysql #8
rlm_sql_mysql: Starting connect to MySQL server for #8
rlm_sql (sql): Connected new DB handle, #8
rlm_sql (sql): starting 9
rlm_sql (sql): Attempting to connect rlm_sql_mysql #9
rlm_sql_mysql: Starting connect to MySQL server for #9
rlm_sql (sql): Connected new DB handle, #9
rlm_sql (sql): starting 10
rlm_sql (sql): Attempting to connect rlm_sql_mysql #10
rlm_sql_mysql: Starting connect to MySQL server for #10
rlm_sql (sql): Connected new DB handle, #10
rlm_sql (sql): starting 11
rlm_sql (sql): Attempting to connect rlm_sql_mysql #11
rlm_sql_mysql: Starting connect to MySQL server for #11
rlm_sql (sql): Connected new DB handle, #11
rlm_sql (sql): starting 12
rlm_sql (sql): Attempting to connect rlm_sql_mysql #12
rlm_sql_mysql: Starting connect to MySQL server for #12
rlm_sql (sql): Connected new DB handle, #12
rlm_sql (sql): starting 13
rlm_sql (sql): Attempting to connect rlm_sql_mysql #13
rlm_sql_mysql: Starting connect to MySQL server for #13
rlm_sql (sql): Connected new DB handle, #13
rlm_sql (sql): starting 14
rlm_sql (sql): Attempting to connect rlm_sql_mysql #14
rlm_sql_mysql: Starting connect to MySQL server for #14
rlm_sql (sql): Connected new DB handle, #14
rlm_sql (sql): starting 15
rlm_sql (sql): Attempting to connect rlm_sql_mysql #15
rlm_sql_mysql: Starting connect to MySQL server for #15
rlm_sql (sql): Connected new DB handle, #15
rlm_sql (sql): starting 16
rlm_sql (sql): Attempting to connect rlm_sql_mysql #16
rlm_sql_mysql: Starting connect to MySQL server for #16
rlm_sql (sql): Connected new DB handle, #16
rlm_sql (sql): starting 17
rlm_sql (sql): Attempting to connect rlm_sql_mysql #17
rlm_sql_mysql: Starting connect to MySQL server for #17
rlm_sql (sql): Connected new DB handle, #17
rlm_sql (sql): starting 18
rlm_sql (sql): Attempting to connect rlm_sql_mysql #18
rlm_sql_mysql: Starting connect to MySQL server for #18
rlm_sql (sql): Connected new DB handle, #18
rlm_sql (sql): starting 19
rlm_sql (sql): Attempting to connect rlm_sql_mysql #19
rlm_sql_mysql: Starting connect to MySQL server for #19
rlm_sql (sql): Connected new DB handle, #19
rlm_sql (sql): starting 20
rlm_sql (sql): Attempting to connect rlm_sql_mysql #20
rlm_sql_mysql: Starting connect to MySQL server for #20
rlm_sql (sql): Connected new DB handle, #20
rlm_sql (sql): starting 21
rlm_sql (sql): Attempting to connect rlm_sql_mysql #21
rlm_sql_mysql: Starting connect to MySQL server for #21
rlm_sql (sql): Connected new DB handle, #21
rlm_sql (sql): starting 22
rlm_sql (sql): Attempting to connect rlm_sql_mysql #22
rlm_sql_mysql: Starting connect to MySQL server for #22
rlm_sql (sql): Connected new DB handle, #22
rlm_sql (sql): starting 23
rlm_sql (sql): Attempting to connect rlm_sql_mysql #23
rlm_sql_mysql: Starting connect to MySQL server for #23
rlm_sql (sql): Connected new DB handle, #23
rlm_sql (sql): starting 24
rlm_sql (sql): Attempting to connect rlm_sql_mysql #24
rlm_sql_mysql: Starting connect to MySQL server for #24
rlm_sql (sql): Connected new DB handle, #24
rlm_sql (sql): starting 25
rlm_sql (sql): Attempting to connect rlm_sql_mysql #25
rlm_sql_mysql: Starting connect to MySQL server for #25
rlm_sql (sql): Connected new DB handle, #25
rlm_sql (sql): starting 26
rlm_sql (sql): Attempting to connect rlm_sql_mysql #26
rlm_sql_mysql: Starting connect to MySQL server for #26
rlm_sql (sql): Connected new DB handle, #26
rlm_sql (sql): starting 27
rlm_sql (sql): Attempting to connect rlm_sql_mysql #27
rlm_sql_mysql: Starting connect to MySQL server for #27
rlm_sql (sql): Connected new DB handle, #27
rlm_sql (sql): starting 28
rlm_sql (sql): Attempting to connect rlm_sql_mysql #28
rlm_sql_mysql: Starting connect to MySQL server for #28
rlm_sql (sql): Connected new DB handle, #28
rlm_sql (sql): starting 29
rlm_sql (sql): Attempting to connect rlm_sql_mysql #29
rlm_sql_mysql: Starting connect to MySQL server for #29
rlm_sql (sql): Connected new DB handle, #29
rlm_sql (sql): starting 30
rlm_sql (sql): Attempting to connect rlm_sql_mysql #30
rlm_sql_mysql: Starting connect to MySQL server for #30
rlm_sql (sql): Connected new DB handle, #30
rlm_sql (sql): starting 31
rlm_sql (sql): Attempting to connect rlm_sql_mysql #31
rlm_sql_mysql: Starting connect to MySQL server for #31
rlm_sql (sql): Connected new DB handle, #31
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating module "acct_unique" from file
/etc/raddb/modules/acct_unique
  acct_unique {
        key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier,
NAS-Port"
  }
 Module: Linked to module rlm_realm
 Module: Instantiating module "suffix" from file /etc/raddb/modules/realm
  realm suffix {
        format = "suffix"
        delimiter = "@"
        ignore_default = no
        ignore_null = no
  }
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating module "detail" from file /etc/raddb/modules/detail
  detail {
        detailfile = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{
Packet-Src-IPv6-Address}}/detail-%Y%m%d"
        header = "%t"
        detailperm = 384
        dirperm = 493
        locking = no
        log_packet_header = no
  }
 Module: Linked to module rlm_sqlippool
 Module: Instantiating module "sqlippool" from file
/etc/raddb/sqlippool.conf
  sqlippool {
        sql-instance-name = "sql"
        lease-duration = 3601
        pool-name = ""
        allocate-begin = "START TRANSACTION"
        allocate-clear = "UPDATE radippool   SET nasipaddress = '',
pool_key = 0,   callingstationid = '', username = '',   calledstationid =
'', expiry_time = NULL   WHERE expiry_time <= NOW() - INTERVAL 1 SECOND
AND pool_name = '%{control:Pool-Name}'"
        allocate-find = "SELECT framedipaddress FROM radippool  WHERE
pool_name = '%{control:Pool-Name}' AND (expiry_time < NOW() OR expiry_time
IS NULL)  LIMIT 1  FOR UPDATE"
        allocate-update = "UPDATE radippool  SET nasipaddress =
'%{NAS-IP-Address}', pool_key = '%{3GPP-IMSI}-%{3GPP-NSAPI}',
 callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}',
 calledstationid = '%{Called-Station-Id}', expiry_time = NOW() + INTERVAL
3601 SECOND  WHERE framedipaddress = '%I' AND (expiry_time < NOW() OR
expiry_time IS NULL)"
        allocate-commit = "COMMIT"
        allocate-rollback = "ROLLBACK"
        pool-check = "SELECT id FROM radippool  WHERE
pool_name='%{control:Pool-Name}' LIMIT 1"
        start-begin = "START TRANSACTION"
        start-update = "UPDATE radippool  SET expiry_time = NOW() +
INTERVAL 3601 SECOND  WHERE nasipaddress = '%{NAS-IP-Address}' AND
 pool_key = '%{3GPP-IMSI}-%{3GPP-NSAPI}'  AND username = '%{User-Name}'
 AND callingstationid = '%{Calling-Station-Id}'  AND framedipaddress =
'%{Framed-IP-Address}'"
        start-commit = "COMMIT"
        start-rollback = "ROLLBACK"
        alive-begin = "START TRANSACTION"
        alive-update = "UPDATE radippool  SET expiry_time = NOW() +
INTERVAL 3601 SECOND  WHERE nasipaddress = '%{Nas-IP-Address}' AND pool_key
= '%{3GPP-IMSI}-%{3GPP-NSAPI}'  AND username = '%{User-Name}'  AND
callingstationid = '%{Calling-Station-Id}'  AND framedipaddress =
'%{Framed-IP-Address}'"
        alive-commit = "COMMIT"
        alive-rollback = "ROLLBACK"
        stop-begin = "START TRANSACTION"
        stop-clear = "UPDATE radippool  SET nasipaddress = '', pool_key =
0, callingstationid = '', username = '',  calledstationid = '', expiry_time
= NULL  WHERE nasipaddress = '%{Nas-IP-Address}' AND pool_key =
'%{3GPP-IMSI}-%{3GPP-NSAPI}'  AND username = '%{User-Name}'  AND
callingstationid = '%{Calling-Station-Id}'  AND framedipaddress =
'%{Framed-IP-Address}'"
        stop-commit = "COMMIT"
        stop-rollback = "ROLLBACK"
        on-begin = "START TRANSACTION"
        on-clear = "UPDATE radippool  SET nasipaddress = '', pool_key = 0,
callingstationid = '', username = '',  expiry_time = NULL  WHERE
nasipaddress = '%{Nas-IP-Address}'"
        on-commit = "COMMIT"
        on-rollback = "ROLLBACK"
        off-begin = "START TRANSACTION"
        off-clear = "UPDATE radippool  SET nasipaddress = '', pool_key = 0,
callingstationid = '', username = '',  expiry_time = NULL  WHERE
nasipaddress = '%{Nas-IP-Address}'"
        off-commit = "COMMIT"
        off-rollback = "ROLLBACK"
        sqlippool_log_exists = "Existing IP: %{reply:Framed-IP-Address}
(did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user
%{User-Name})"
        sqlippool_log_success = "Allocated IP: %{reply:Framed-IP-Address}
from %{control:Pool-Name}   (did %{Called-Station-Id} cli
%{Calling-Station-Id} port %{NAS-Port} user %{User-Name})"
        sqlippool_log_clear = "Released IP %{Framed-IP-Address} (did
%{Called-Station-Id} cli %{Calling-Station-Id} user %{User-Name})"
        sqlippool_log_failed = "IP Allocation FAILED from
%{control:Pool-Name}   (did %{Called-Station-Id} cli %{Calling-Station-Id}
port %{NAS-Port} user %{User-Name})"
        sqlippool_log_nopool = "No Pool-Name defined   (did
%{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user
%{User-Name})"
        defaultpool = "main_pool"
  }
 Module: Linked to module rlm_attr_filter
 Module: Instantiating module "attr_filter.accounting_response" from file
/etc/raddb/modules/attr_filter
  attr_filter attr_filter.accounting_response {
        attrsfile = "/etc/raddb/attrs.accounting_response"
        key = "%{User-Name}"
        relaxed = no
  }
reading pairlist file /etc/raddb/attrs.accounting_response
 Module: Checking session {...} for more modules to load
 Module: Linked to module rlm_radutmp
 Module: Instantiating module "radutmp" from file /etc/raddb/modules/radutmp
  radutmp {
        filename = "/var/log/radius/radutmp"
        username = "%{User-Name}"
        case_sensitive = yes
        check_with_nas = yes
        perm = 384
        callerid = yes
  }
 Module: Checking post-proxy {...} for more modules to load
 Module: Linked to module rlm_eap
 Module: Instantiating module "eap" from file /etc/raddb/eap.conf
  eap {
        default_eap_type = "md5"
        timer_expire = 60
        ignore_unknown_eap_types = no
        cisco_accounting_username_bug = no
        max_sessions = 1024
  }
 Module: Linked to sub-module rlm_eap_md5
 Module: Instantiating eap-md5
 Module: Linked to sub-module rlm_eap_leap
 Module: Instantiating eap-leap
 Module: Linked to sub-module rlm_eap_gtc
 Module: Instantiating eap-gtc
   gtc {
        challenge = "Password: "
        auth_type = "PAP"
   }
 Module: Linked to sub-module rlm_eap_tls
 Module: Instantiating eap-tls
   tls {
        rsa_key_exchange = no
        dh_key_exchange = yes
        rsa_key_length = 512
        dh_key_length = 512
        verify_depth = 0
        CA_path = "/etc/raddb/certs"
        pem_file_type = yes
        private_key_file = "/etc/raddb/certs/server.pem"
        certificate_file = "/etc/raddb/certs/server.pem"
        CA_file = "/etc/raddb/certs/ca.pem"
        private_key_password = "whatever"
        dh_file = "/etc/raddb/certs/dh"
        fragment_size = 1024
        include_length = yes
        check_crl = no
        cipher_list = "DEFAULT"
        ecdh_curve = "prime256v1"
    cache {
        enable = no
        lifetime = 24
        max_entries = 255
    }
    verify {
    }
    ocsp {
        enable = no
        override_cert_url = yes
        url = "http://127.0.0.1/ocsp/"
        use_nonce = yes
        timeout = 0
        softfail = no
    }
   }
 Module: Linked to sub-module rlm_eap_ttls
 Module: Instantiating eap-ttls
   ttls {
        default_eap_type = "md5"
        copy_request_to_tunnel = no
        use_tunneled_reply = no
        virtual_server = "inner-tunnel"
        include_length = yes
   }
 Module: Linked to sub-module rlm_eap_peap
 Module: Instantiating eap-peap
   peap {
        default_eap_type = "mschapv2"
        copy_request_to_tunnel = no
        use_tunneled_reply = no
        proxy_tunneled_request_as_eap = yes
        virtual_server = "inner-tunnel"
        soh = no
   }
 Module: Linked to sub-module rlm_eap_mschapv2
 Module: Instantiating eap-mschapv2
   mschapv2 {
        with_ntdomain_hack = no
        send_error = no
   }
 Module: Checking post-auth {...} for more modules to load
 Module: Linked to module rlm_always
 Module: Instantiating module "noop" from file /etc/raddb/modules/always
  always noop {
        rcode = "noop"
        simulcount = 0
        mpp = no
  }
 Module: Instantiating module "attr_filter.access_reject" from file
/etc/raddb/modules/attr_filter
  attr_filter attr_filter.access_reject {
        attrsfile = "/etc/raddb/attrs.access_reject"
        key = "%{User-Name}"
        relaxed = no
  }
reading pairlist file /etc/raddb/attrs.access_reject
 } # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
        type = "auth"
        ipaddr = 127.0.0.1
        port = 0
}
listen {
        type = "acct"
        ipaddr = 127.0.0.1
        port = 0
}
 ... adding new socket proxy address * port 40388
Listening on authentication address 127.0.0.1 port 1812
Listening on accounting address 127.0.0.1 port 1813
Listening on proxy address * port 1297
Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1 port 54156, id=187,
length=103
        User-Name = "123123000@internet"
        Framed-IP-Address = 5.17.0.15
        Called-Station-Id = "internet"
        Calling-Station-Id = "0034687947939"
        3GPP-IMSI = "123123000000000"
        3GPP-NSAPI = "5"
# Executing section authorize from file /etc/raddb/sites-enabled/default
+group authorize {
++[preprocess] = ok
[files] users: Matched entry DEFAULT at line 50
++[files] = ok
[sql]   expand: %{User-Name} -> 123123000@internet
[sql] sql_set_user escaped user --> '123123000@internet'
rlm_sql (sql): Reserving sql socket id: 30
[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 = '123123000@internet'           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 = '123123000@internet'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup
WHERE username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT
groupname           FROM radusergroup           WHERE username =
'123123000@internet'           ORDER BY priority
rlm_sql (sql): Released sql socket id: 30
++[sql] = ok
++[expiration] = noop
++[logintime] = noop
+} # group authorize = ok
Found Auth-Type = Accept
Auth-Type = Accept, accepting the user
# Executing section post-auth from file /etc/raddb/sites-enabled/default
+group post-auth {
++? if ("%{User-Name}" == "XTaskRadiusServerPing")
        expand: %{User-Name} -> 123123000@internet
? Evaluating ("%{User-Name}" == "XTaskRadiusServerPing") -> FALSE
++? if ("%{User-Name}" == "XTaskRadiusServerPing") -> FALSE
++else else {
rlm_sql (sql): Reserving sql socket id: 29
[sqlippool]     expand: %{User-Name} -> 123123000@internet
[sqlippool] sql_set_user escaped user --> '123123000@internet'
[sqlippool]     expand: START TRANSACTION -> START TRANSACTION
[sqlippool]     expand: UPDATE radippool   SET nasipaddress = '', pool_key
= 0,   callingstationid = '', username = '',   calledstationid = '',
expiry_time = NULL   WHERE expiry_time <= NOW() - INTERVAL 1 SECOND   AND
pool_name = '%{control:Pool-Name}' -> UPDATE radippool   SET nasipaddress =
'', pool_key = 0,   callingstationid = '', username = '',   calledstationid
= '', expiry_time = NULL   WHERE expiry_time <= NOW() - INTERVAL 1 SECOND
AND pool_name = 'tochada'
[sqlippool]     expand: COMMIT -> COMMIT
[sqlippool]     expand: START TRANSACTION -> START TRANSACTION
[sqlippool]     expand: SELECT framedipaddress FROM radippool  WHERE
pool_name = '%{control:Pool-Name}' AND (expiry_time < NOW() OR expiry_time
IS NULL)  LIMIT 1  FOR UPDATE -> SELECT framedipaddress FROM radippool
 WHERE pool_name = 'tochada' AND (expiry_time < NOW() OR expiry_time IS
NULL)  LIMIT 1  FOR UPDATE
[sqlippool]     expand: UPDATE radippool  SET nasipaddress =
'%{NAS-IP-Address}', pool_key = '%{3GPP-IMSI}-%{3GPP-NSAPI}',
 callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}',
 calledstationid = '%{Called-Station-Id}', expiry_time = NOW() + INTERVAL
3601 SECOND  WHERE framedipaddress = '5.0.0.5' AND (expiry_time < NOW() OR
expiry_time IS NULL) -> UPDATE radippool  SET nasipaddress = '127.0.0.1',
pool_key = '123123000000000-5',  callingstationid = '0034687947939',
username = '123123000@internet',  calledstationid = 'internet', expiry_time
= NOW() + INTERVAL 3601 SECOND  WHERE framedipaddress = '5.0.0.5' AND
(expiry_time < NOW() OR expiry_time IS NULL)
[sqlippool] Allocated IP 5.0.0.5 [05000005]
[sqlippool]     expand: COMMIT -> COMMIT
rlm_sql (sql): Released sql socket id: 29
[sqlippool]     expand: Allocated IP: %{reply:Framed-IP-Address} from
%{control:Pool-Name}   (did %{Called-Station-Id} cli %{Calling-Station-Id}
port %{NAS-Port} user %{User-Name}) -> Allocated IP: 5.0.0.5 from tochada
(did internet cli 0034687947939 port  user 123123000@internet)
Allocated IP: 5.0.0.5 from tochada   (did internet cli 0034687947939 port
 user 123123000@internet)
+++[sqlippool] = ok
+++update reply {
        expand: modules.sqlippool.lease-duration -> modules.sqlippool.lease-
duration
        expand: %{config:modules.sqlippool.lease-duration} -> 3601
+++} # update reply = noop
++} # else else = ok
++[exec] = noop
+} # group post-auth = ok
Sending Access-Accept of id 187 to 127.0.0.1 port 54156
        MS-Primary-DNS-Server = 8.8.8.8
        Framed-IP-Address = 5.0.0.5
        Session-Timeout = 3601
Finished request 1.
Going to the next request
Waking up in 4.7 seconds.

Framed-IP-Address into Access-Request is not processed

José María López Otero