rlm_cache

3 Sep 2014

      Hi,

I`m playing with rlm_cache. I want to cache auth request to speed up future processing of the same auth request. If I send second request (the same as first one), I got reject :(.
Could you please help, me. Thx.

mods-enabled/cache:
...
update {
        request: := &request:
        control: := &control:
        reply: := &reply:
}
...

sites-enabled/default:

authorize {
    verify_nas
    preprocess
    chap
    suffix
    update control {
        Cache-Status-Only := 'yes'
    }
    cache
    if (notfound) {
        files
        update control {
            Cache-Status-Only := 'no'
        }
        cache
    }
    pap
}

Debug output:
radiusd: FreeRADIUS Version 3.0.3, for host i686-pc-linux-gnu, built on Sep  1 2014 at 21:59:53
Copyright (C) 1999-2014 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 dictionary file /mnt/sdcard/software/freeradius-server-3.0.3/share/freeradius/dictionary
including dictionary file /mnt/sdcard/software/freeradius-server-3.0.3/share/freeradius/dictionary.dhcp
including dictionary file /mnt/sdcard/software/freeradius-server-3.0.3/share/freeradius/dictionary.vqp
including dictionary file ./dictionary
including configuration file ./radiusd.conf
including configuration file ./proxy.conf
including configuration file ./clients.conf
including files in directory ./mods-enabled/
including configuration file ./mods-enabled/digest
including configuration file ./mods-enabled/pap
including configuration file ./mods-enabled/cache
including configuration file ./mods-enabled/attr_filter
including configuration file ./mods-enabled/chap
including configuration file ./mods-enabled/linelog
including configuration file ./mods-enabled/expr
including configuration file ./mods-enabled/preprocess
including configuration file ./mods-enabled/realm
including configuration file ./mods-enabled/unpack
including configuration file ./mods-enabled/files
including configuration file ./mods-enabled/always
including files in directory ./policy.d/
including configuration file ./policy.d/cui
including configuration file ./policy.d/control
including configuration file ./policy.d/filter
including configuration file ./policy.d/eap
including configuration file ./policy.d/nas
including configuration file ./policy.d/accounting
including configuration file ./policy.d/dhcp
including configuration file ./policy.d/operator-name
including configuration file ./policy.d/canonicalization
including files in directory ./sites-enabled/
including configuration file ./sites-enabled/default
main {
                name = "radiusd"
                prefix = "/mnt/sdcard/software/freeradius-server-3.0.3"
                localstatedir = "/mnt/sdcard/software/freeradius-server-3.0.3/var"
                sbindir = "/mnt/sdcard/software/freeradius-server-3.0.3/sbin"
                logdir = "/mnt/sdcard/software/freeradius-server-3.0.3/var/log/radius"
                run_dir = "/mnt/sdcard/software/freeradius-server-3.0.3/var/run/radiusd"
                libdir = "/mnt/sdcard/software/freeradius-server-3.0.3/lib"
                radacctdir = "/mnt/sdcard/software/freeradius-server-3.0.3/var/log/radius/radacct"
                hostname_lookups = no
                max_request_time = 30
                cleanup_delay = 5
                max_requests = 1024
                pidfile = "/mnt/sdcard/software/freeradius-server-3.0.3/var/run/radiusd/radiusd.pid"
                checkrad = "/mnt/sdcard/software/freeradius-server-3.0.3/sbin/checkrad"
                debug_level = 0
                proxy_requests = yes
log {
               stripped_names = no
               auth = yes
               auth_badpass = yes
               auth_goodpass = yes
               colourise = yes
               msg_denied = "You are already logged in - access denied"
}
security {
               max_attributes = 200
               reject_delay = 1
               status_server = yes
               allow_vulnerable_openssl = "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 = <<< secret >>>
               response_window = 20
               max_outstanding = 65536
               zombie_period = 40
               status_check = "status-server"
               ping_interval = 30
               check_interval = 30
               num_answers_to_alive = 3
               revive_interval = 120
               status_check_timeout = 4
  coa {
                irt = 2
                mrt = 16
                mrc = 5
                mrd = 30
  }
  limit {
                max_connections = 16
                max_requests = 0
                lifetime = 0
                idle_timeout = 0
  }
}
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 = <<< secret >>>
               nas_type = "other"
               proto = "*"
  limit {
                max_connections = 16
                lifetime = 0
                idle_timeout = 30
  }
}
radiusd: #### Instantiating modules ####
instantiate {
}
modules {
  # Loaded module rlm_digest
  # Instantiating module "digest" from file ./mods-enabled/digest
  # Loaded module rlm_pap
  # Instantiating module "pap" from file ./mods-enabled/pap
  pap {
                normalise = yes
  }
  # Loaded module rlm_cache
  # Instantiating module "cache" from file ./mods-enabled/cache
  cache {
                key = "%{User-Name}"
                ttl = 86400
                max_entries = 16384
                epoch = 0
                add_stats = yes
  }
  # Loaded module rlm_attr_filter
  # Instantiating module "attr_filter.post-proxy" from file ./mods-enabled/attr_filter
  attr_filter attr_filter.post-proxy {
                filename = "./mods-config/attr_filter/post-proxy"
                key = "%{Realm}"
                relaxed = no
  }
reading pairlist file ./mods-config/attr_filter/post-proxy
  # Instantiating module "attr_filter.pre-proxy" from file ./mods-enabled/attr_filter
  attr_filter attr_filter.pre-proxy {
                filename = "./mods-config/attr_filter/pre-proxy"
                key = "%{Realm}"
                relaxed = no
  }
reading pairlist file ./mods-config/attr_filter/pre-proxy
  # Instantiating module "attr_filter.access_reject" from file ./mods-enabled/attr_filter
  attr_filter attr_filter.access_reject {
                filename = "./mods-config/attr_filter/access_reject"
                key = "%{User-Name}"
                relaxed = no
  }
reading pairlist file ./mods-config/attr_filter/access_reject
  # Instantiating module "attr_filter.access_challenge" from file ./mods-enabled/attr_filter
  attr_filter attr_filter.access_challenge {
                filename = "./mods-config/attr_filter/access_challenge"
                key = "%{User-Name}"
                relaxed = no
  }
reading pairlist file ./mods-config/attr_filter/access_challenge
  # Instantiating module "attr_filter.accounting_response" from file ./mods-enabled/attr_filter
  attr_filter attr_filter.accounting_response {
                filename = "./mods-config/attr_filter/accounting_response"
                key = "%{User-Name}"
                relaxed = no
  }
reading pairlist file ./mods-config/attr_filter/accounting_response
  # Loaded module rlm_chap
  # Instantiating module "chap" from file ./mods-enabled/chap
  # Loaded module rlm_linelog
  # Instantiating module "linelog" from file ./mods-enabled/linelog
  linelog {
                filename = "/mnt/sdcard/software/freeradius-server-3.0.3/var/log/radius/linelog"
                permissions = 384
                format = "This is a log message for %{User-Name}"
                reference = "messages.%{%{Packet-Type}:-default}"
  }
  # Instantiating module "log_accounting" from file ./mods-enabled/linelog
  linelog log_accounting {
                filename = "/mnt/sdcard/software/freeradius-server-3.0.3/var/log/radius/linelog-accounting"
                permissions = 384
                format = ""
                reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}"
  }
  # Loaded module rlm_expr
  # Instantiating module "expr" from file ./mods-enabled/expr
  expr {
                safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
  # Loaded module rlm_preprocess
  # Instantiating module "preprocess" from file ./mods-enabled/preprocess
  preprocess {
                huntgroups = "./mods-config/preprocess/huntgroups"
                hints = "./mods-config/preprocess/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 ./mods-config/preprocess/huntgroups
reading pairlist file ./mods-config/preprocess/hints
  # Loaded module rlm_realm
  # Instantiating module "IPASS" from file ./mods-enabled/realm
  realm IPASS {
                format = "prefix"
                delimiter = "/"
                ignore_default = no
                ignore_null = no
  }
  # Instantiating module "suffix" from file ./mods-enabled/realm
  realm suffix {
                format = "suffix"
                delimiter = "@"
                ignore_default = no
                ignore_null = no
  }
  # Instantiating module "realmpercent" from file ./mods-enabled/realm
  realm realmpercent {
               format = "suffix"
                delimiter = "%"
                ignore_default = no
                ignore_null = no
  }
  # Instantiating module "ntdomain" from file ./mods-enabled/realm
  realm ntdomain {
                format = "prefix"
                delimiter = "\"
                ignore_default = no
                ignore_null = no
  }
  # Loaded module rlm_unpack
  # Instantiating module "unpack" from file ./mods-enabled/unpack
  # Loaded module rlm_files
  # Instantiating module "files" from file ./mods-enabled/files
  files {
                filename = "./mods-config/files/authorize"
                usersfile = "./mods-config/files/authorize"
                acctusersfile = "./mods-config/files/accounting"
                preproxy_usersfile = "./mods-config/files/pre-proxy"
                compat = "cistron"
  }
reading pairlist file ./mods-config/files/authorize
[./mods-config/files/authorize]:83 Cistron compatibility checks for entry dummy ...
[./mods-config/files/authorize]:191 Cistron compatibility checks for entry DEFAULT ...
[./mods-config/files/authorize]:198 Cistron compatibility checks for entry DEFAULT ...
[./mods-config/files/authorize]:205 Cistron compatibility checks for entry DEFAULT ...
reading pairlist file ./mods-config/files/authorize
[./mods-config/files/authorize]:83 Cistron compatibility checks for entry dummy ...
[./mods-config/files/authorize]:191 Cistron compatibility checks for entry DEFAULT ...
[./mods-config/files/authorize]:198 Cistron compatibility checks for entry DEFAULT ...
[./mods-config/files/authorize]:205 Cistron compatibility checks for entry DEFAULT ...
reading pairlist file ./mods-config/files/accounting
reading pairlist file ./mods-config/files/pre-proxy
  # Loaded module rlm_always
  # Instantiating module "reject" from file ./mods-enabled/always
  always reject {
                rcode = "reject"
                simulcount = 0
                mpp = no
  }
  # Instantiating module "fail" from file ./mods-enabled/always
  always fail {
                rcode = "fail"
                simulcount = 0
                mpp = no
  }
  # Instantiating module "ok" from file ./mods-enabled/always
  always ok {
                rcode = "ok"
                simulcount = 0
                mpp = no
  }
  # Instantiating module "handled" from file ./mods-enabled/always
  always handled {
                rcode = "handled"
                simulcount = 0
                mpp = no
  }
  # Instantiating module "invalid" from file ./mods-enabled/always
  always invalid {
                rcode = "invalid"
                simulcount = 0
                mpp = no
  }
  # Instantiating module "userlock" from file ./mods-enabled/always
  always userlock {
                rcode = "userlock"
                simulcount = 0
                mpp = no
  }
  # Instantiating module "notfound" from file ./mods-enabled/always
  always notfound {
                rcode = "notfound"
                simulcount = 0
                mpp = no
  }
  # Instantiating module "noop" from file ./mods-enabled/always
  always noop {
                rcode = "noop"
                simulcount = 0
                mpp = no
  }
  # Instantiating module "updated" from file ./mods-enabled/always
  always updated {
                rcode = "updated"
                simulcount = 0
                mpp = no
  }
} # modules
radiusd: #### Loading Virtual Servers ####
server { # from file ./radiusd.conf
} # server
server default { # from file ./sites-enabled/default
# Loading authenticate {...}
# Loading authorize {...}
Ignoring "sql" (see raddb/mods-available/README.rst)
Ignoring "ldap" (see raddb/mods-available/README.rst)
# Loading preacct {...}
# Loading accounting {...}
# Loading post-auth {...}
} # server default
radiusd: #### Opening IP addresses and Ports ####
listen {
                type = "auth"
                ipaddr = *
                port = 0
   limit {
                max_connections = 16
                lifetime = 0
                idle_timeout = 30
   }
}
listen {
                type = "acct"
                ipaddr = *
                port = 0
   limit {
                max_connections = 16
                lifetime = 0
                idle_timeout = 30
   }
}
Listening on auth address * port 1812 as server default
Listening on acct address * port 1813 as server default
Opening new proxy socket 'proxy address * port 0'
Listening on proxy address * port 53265
Ready to process requests.
Received Access-Request Id 34 from 127.0.0.1:51488 to 127.0.0.1:1812 length 95
                NAS-Port-Type = Virtual
                Service-Type = Framed-User
                Framed-Protocol = PPP
                User-Name = 'dummy'
                User-Password = 'dummy'
                Connect-Info = '8640000'
                NAS-Port = 411
                NAS-Port-Id = 'Uniq-Sess-ID411'
(0) # Executing section authorize from file ./sites-enabled/default
(0)   authorize {
(0)   verify_nas verify_nas {
(0)     if ( ! NAS-IP-Address )
(0)     if ( ! NAS-IP-Address )  -> TRUE
(0)    if ( ! NAS-IP-Address )  {
(0)     update  {
(0) EXPAND %{Packet-Src-IP-Address}
(0)    --> 127.0.0.1
(0)          NAS-IP-Address := 127.0.0.1
(0)     } # update  = noop
(0)    } # if ( ! NAS-IP-Address )  = noop
(0)   } # verify_nas verify_nas = noop
(0)   [preprocess] = ok
(0)   [chap] = noop
(0) suffix : No '@' in User-Name = "dummy", looking up realm NULL
(0) suffix : No such realm "NULL"
(0)   [suffix] = noop
(0)   update control {
(0)          Cache-Status-Only := yes
(0)   } # update control = noop
(0) cache : EXPAND %{User-Name}
(0) cache :    --> dummy
(0)   [cache] = notfound
(0)    if (notfound)
(0)    if (notfound)  -> TRUE
(0)   if (notfound)  {
(0) files : users: Matched entry dummy at line 83
(0)    [files] = ok
(0)    update control {
(0)          Cache-Status-Only := no
(0)    } # update control = noop
(0) cache : EXPAND %{User-Name}
(0) cache :    --> dummy
(0) cache : Creating entry for "dummy"
(0) cache :           request: := &request:NAS-Port-Type
(0) cache :           request: := &request:Service-Type
(0) cache :           request: := &request:Framed-Protocol
(0) cache :           request: := &request:User-Name
(0) cache :           request: := &request:User-Password
(0) cache :           request: := &request:Connect-Info
(0) cache :           request: := &request:NAS-Port
(0) cache :           request: := &request:NAS-Port-Id
(0) cache :           request: := &request:NAS-IP-Address
(0) cache :           request: := &request:Huntgroup-Name
(0) cache :           control: := &config:Cleartext-Password
(0) cache :           skipping Cache-Status-Only
(0) cache :           reply: := &reply:Service-Type
(0) cache :           reply: := &reply:Framed-Protocol
(0) cache :           reply: := &reply:Framed-IP-Address
(0) cache :           reply: := &reply:Framed-IP-Netmask
(0) cache :           reply: := &reply:Framed-Routing
(0) cache :           reply: := &reply:Framed-Filter-Id
(0) cache :           reply: := &reply:Framed-MTU
(0) cache :           reply: := &reply:Framed-Compression
(0) cache : Inserted entry, TTL 86400 seconds
(0)    [cache] = updated
(0)   } # if (notfound)  = updated
(0)   [pap] = updated
(0)  } #  authorize = updated
(0) Found Auth-Type = PAP
(0) # Executing group from file ./sites-enabled/default
(0)  Auth-Type PAP {
(0) pap : Login attempt with password
(0) pap : User authenticated successfully
(0)   [pap] = ok
(0)  } # Auth-Type PAP = ok
(0) Login OK: [dummy/dummy] (from client localhost port 411)
(0) # Executing section post-auth from file ./sites-enabled/default
(0)   post-auth {
(0)   remove_reply_message_if_eap remove_reply_message_if_eap {
(0)     if (reply:EAP-Message && reply:Reply-Message)
(0)     if (reply:EAP-Message && reply:Reply-Message)  -> FALSE
(0)    else else {
(0)     [noop] = noop
(0)    } # else else = noop
(0)   } # remove_reply_message_if_eap remove_reply_message_if_eap = noop
(0)  } #  post-auth = noop
Sending Access-Accept Id 34 from 127.0.0.1:1812 to 127.0.0.1:51488
                Service-Type = Framed-User
                Framed-Protocol = PPP
                Framed-IP-Address = 172.16.3.33
                Framed-IP-Netmask = 255.255.255.0
                Framed-Routing = Broadcast-Listen
                Framed-Filter-Id = 'std.ppp'
                Framed-MTU = 1500
                Framed-Compression = Van-Jacobson-TCP-IP
(0) Finished request
Waking up in 0.3 seconds.
Waking up in 4.6 seconds.

(0) Cleaning up request packet ID 34 with timestamp +3
Ready to process requests.
Received Access-Request Id 243 from 127.0.0.1:59013 to 127.0.0.1:1812 length 95
                NAS-Port-Type = Virtual
                Service-Type = Framed-User
                Framed-Protocol = PPP
                User-Name = 'dummy'
                User-Password = 'dummy'
                Connect-Info = '8640000'
                NAS-Port = 411
                NAS-Port-Id = 'Uniq-Sess-ID411'
(1) # Executing section authorize from file ./sites-enabled/default
(1)   authorize {
(1)   verify_nas verify_nas {
(1)     if ( ! NAS-IP-Address )
(1)     if ( ! NAS-IP-Address )  -> TRUE
(1)    if ( ! NAS-IP-Address )  {
(1)     update  {
(1) EXPAND %{Packet-Src-IP-Address}
(1)    --> 127.0.0.1
(1)          NAS-IP-Address := 127.0.0.1
(1)     } # update  = noop
(1)    } # if ( ! NAS-IP-Address )  = noop
(1)   } # verify_nas verify_nas = noop
(1)   [preprocess] = ok
(1)   [chap] = noop
(1) suffix : No '@' in User-Name = "dummy", looking up realm NULL
(1) suffix : No such realm "NULL"
(1)   [suffix] = noop
(1)   update control {
(1)          Cache-Status-Only := yes
(1)   } # update control = noop
(1) cache : EXPAND %{User-Name}
(1) cache :    --> dummy
(1) cache : Found entry for "dummy"
(1)   [cache] = ok
(1)    if (notfound)
(1)    if (notfound)  -> FALSE
(1) WARNING: pap : No "known good" password found for the user.  Not setting Auth-Type.
(1) WARNING: pap : Authentication will fail unless a "known good" password is available.
(1)   [pap] = noop
(1)  } #  authorize = ok
(1) ERROR: No Auth-Type found: rejecting the user via Post-Auth-Type = Reject
(1) Failed to authenticate the user.
(1) Login incorrect (No Auth-Type found: rejecting the user via Post-Auth-Type = Reject): [dummy/dummy] (from client localhost port 411)
(1) Using Post-Auth-Type Reject
(1) # Executing group from file ./sites-enabled/default
(1)  Post-Auth-Type REJECT {
(1)   remove_reply_message_if_eap remove_reply_message_if_eap {
(1)     if (reply:EAP-Message && reply:Reply-Message)
(1)     if (reply:EAP-Message && reply:Reply-Message)  -> FALSE
(1)    else else {
(1)     [noop] = noop
(1)    } # else else = noop
(1)   } # remove_reply_message_if_eap remove_reply_message_if_eap = noop
(1)  } # Post-Auth-Type REJECT = noop
(1) Delaying response for 1 seconds
Waking up in 0.3 seconds.
Waking up in 0.6 seconds.
(1) Sending delayed response
Sending Access-Reject Id 243 from 127.0.0.1:1812 to 127.0.0.1:59013
Waking up in 3.9 seconds.
(1) Cleaning up request packet ID 243 with timestamp +10
Ready to process requests.

Peter

rlm_cache

BALSIANOK, Peter