redis_ippool module doesnot process lease_time in ack

23 Apr 2019

      Hi,

I have redis_ippool module with below configurations,
        offer_time = 120
        lease_time = 3600

During offer 120 seconds is assigned. During ack the same 120 seconds is returned instead of assigning 3600 seconds.

Debug output:
# /usr/local/sbin/radiusd -X
Info  : FreeRADIUS Version 4.0.0
Info  : Copyright 1999-2018 The FreeRADIUS server project and contributors
Info  : There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Info  : PARTICULAR PURPOSE
Info  : You may redistribute copies of FreeRADIUS under the terms of the
Info  : GNU General Public License
Info  : For more information about these matters, see the file named COPYRIGHT
Info  : Starting - reading configuration files ...
Debug : Including dictionary file "/usr/local/share/freeradius/dictionary"
Debug : Including dictionary file "/usr/local/etc/raddb/dictionary"
Debug : including configuration file /usr/local/etc/raddb/radiusd.conf
Debug : including configuration file /usr/local/etc/raddb/clients.conf
Debug : Including files in directory "/usr/local/etc/raddb/mods-enabled/"
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/always
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/attr_filter
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/cache_eap
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/chap
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/client
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/detail
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/detail.log
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/digest
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/dhcpv4
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/echo
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/escape
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/exec
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/expiration
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/expr
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/files
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/linelog
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/logintime
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/mschap
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/ntlm_auth
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/pap
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/passwd
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/radius
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/radutmp
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/sradutmp
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/stats
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/unix
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/unpack
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/utf8
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/redis_ippool
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/redis
Debug : Including files in directory "/usr/local/etc/raddb/policy.d/"
Debug : including configuration file /usr/local/etc/raddb/policy.d/abfab-tr
Debug : including configuration file /usr/local/etc/raddb/policy.d/accounting
Debug : including configuration file /usr/local/etc/raddb/policy.d/canonicalization
Debug : including configuration file /usr/local/etc/raddb/policy.d/control
Debug : including configuration file /usr/local/etc/raddb/policy.d/cui
Debug : including configuration file /usr/local/etc/raddb/policy.d/debug
Debug : including configuration file /usr/local/etc/raddb/policy.d/dhcp
Debug : including configuration file /usr/local/etc/raddb/policy.d/eap
Debug : including configuration file /usr/local/etc/raddb/policy.d/operator-name
Debug : including configuration file /usr/local/etc/raddb/policy.d/time
Debug : including configuration file /usr/local/etc/raddb/policy.d/vendor
Debug : including configuration file /usr/local/etc/raddb/policy.d/filter
Debug : Including files in directory "/usr/local/etc/raddb/sites-enabled/"
Debug : including configuration file /usr/local/etc/raddb/sites-enabled/dhcp
Debug : Loading dictionary proto_dhcpv4
Info  : Loaded module "proto_dhcpv4"
Debug : Parsing security rules to bootstrap UID / GID / chroot / etc.
Debug : main {
Debug :   security {
Debug :     allow_core_dumps = no
Debug :     allow_vulnerable_openssl = "no"
Debug :   }
Debug :   name = radiusd
Debug :   name = "radiusd"
Debug :   prefix = "/usr/local"
Debug :   local_state_dir = "/usr/local/var"
Debug :   run_dir = "/usr/local/var/run/radiusd"
Debug : }
Debug : Parsing main configuration.
Debug : main {
Debug :   server dhcp {
Debug :     namespace = "dhcpv4"
Debug :     listen {
Debug :       type = DHCP-Discover
Info  : Loaded module "proto_dhcpv4_base"
Debug :       type = DHCP-Request
Debug :       type = DHCP-Inform
Debug :       type = DHCP-Release
Debug :       type = DHCP-Decline
Debug :       transport = udp
Debug : Loading dictionary proto_dhcpv4_udp
Info  : Loaded module "proto_dhcpv4_udp"
Debug :       udp {
Debug :         ipaddr = 10.43.16.207
Debug :         src_ipaddr = 10.43.16.207
Debug :         port = 67
Debug :         broadcast = no
Debug :         networks {
Debug :         }
Debug :         max_packet_size = 4096
Debug :         max_attributes = 0
Debug :       }
Debug :       limit {
Debug :         idle_timeout = 30.000000
Debug :         nak_lifetime = 30.000000
Debug :         max_connections = 1024
Debug :         max_clients = 256
Debug :         max_pending_packets = 256
Debug :         priority {
Debug :           DHCP-Discover = normal
Debug :           DHCP-Request = normal
Debug :           DHCP-Decline = normal
Debug :           DHCP-Release = normal
Debug :           DHCP-Inform = normal
Debug :           DHCP-Lease-Query = low
Debug :           DHCP-Bulk-Lease-Query = low
Debug :         }
Debug :       }
Debug :     }
Debug :   }
Debug :   security {
Debug :   }
Debug :   sbin_dir = "/usr/local/sbin"
Debug :   logdir = "/usr/local/var/log/radius"
Debug :   libdir = "/usr/local/lib"
Debug :   radacctdir = "/usr/local/var/log/radius/radacct"
Debug :   reverse_lookups = no
Debug :   reverse_lookups = no
Debug :   hostname_lookups = yes
Debug :   hostname_lookups = yes
Debug :   max_request_time = 30
Debug :   max_request_time = 30
Debug :   pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
Debug :   debug_level = 0
Debug :   log {
Debug :     colourise = yes
Debug :   }
Debug :   resources {
Debug :   }
Debug :   thread pool {
Debug :     num_networks = 1
Debug :     num_networks = 1
Debug :     num_workers = 4
Debug :     num_workers = 4
Debug :   }
Debug : }
Switching to configured log settings
radiusd: #### Loading Clients ####
  client localhost {
    ipaddr = 127.0.0.1
    require_message_authenticator = no
    secret = <<< secret >>>
    proto = "*"
    limit {
      max_connections = 16
      lifetime = 0
      idle_timeout = 30
    }
  }
  client localhost_ipv6 {
    ipv6addr = ::1
    require_message_authenticator = no
    secret = <<< secret >>>
    limit {
      max_connections = 16
      lifetime = 0
      idle_timeout = 30
    }
  }
  client 10.0.0.0 {
    ipaddr = 10.0.0.0/8
    require_message_authenticator = no
    limit {
      max_connections = 16
      lifetime = 0
      idle_timeout = 30
    }
  }
Debugger not attached
#### Bootstrapping listeners ####
#### Bootstrapping modules ####
modules {
Loaded module "rlm_always"
    always reject {
      rcode = "reject"
      simulcount = 0
      mpp = no
    }
    always fail {
      rcode = "fail"
      simulcount = 0
      mpp = no
    }
    always ok {
      rcode = "ok"
      simulcount = 0
      mpp = no
    }
    always handled {
      rcode = "handled"
      simulcount = 0
      mpp = no
    }
    always invalid {
      rcode = "invalid"
      simulcount = 0
      mpp = no
    }
    always userlock {
      rcode = "userlock"
      simulcount = 0
      mpp = no
    }
    always notfound {
      rcode = "notfound"
      simulcount = 0
      mpp = no
    }
    always noop {
      rcode = "noop"
      simulcount = 0
      mpp = no
    }
    always updated {
      rcode = "updated"
      simulcount = 0
      mpp = no
    }
Loading dictionary rlm_attr_filter
Loaded module "rlm_attr_filter"
    attr_filter attr_filter.pre-proxy {
      filename = "/usr/local/etc/raddb/mods-config/attr_filter/pre-proxy"
      relaxed = no
    }
    attr_filter attr_filter.post-proxy {
      filename = "/usr/local/etc/raddb/mods-config/attr_filter/post-proxy"
      relaxed = no
    }
    attr_filter attr_filter.access_reject {
      filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_reject"
      relaxed = no
    }
    attr_filter attr_filter.access_challenge {
      filename = "/usr/local/etc/raddb/mods-config/attr_filter/access_challenge"
      relaxed = no
    }
    attr_filter attr_filter.accounting_response {
      filename = "/usr/local/etc/raddb/mods-config/attr_filter/accounting_response"
      relaxed = no
    }
Loading dictionary rlm_cache
Loaded module "rlm_cache"
    cache cache_eap {
      driver = "rlm_cache_rbtree"
      ttl = 15
      max_entries = 0
      epoch = 0
      add_stats = no
    }
Loading dictionary rlm_chap
Loaded module "rlm_chap"
Loaded module "rlm_client"
Loading dictionary rlm_detail
Loaded module "rlm_detail"
    detail {
      filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y-%m-%d"
      header = "%t"
      permissions = 384
      locking = no
      escape_filenames = no
      log_packet_header = no
    }
    detail auth_log {
      filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y-%m-%d"
      header = "%t"
      permissions = 384
      locking = no
      escape_filenames = no
      log_packet_header = no
    }
    detail reply_log {
      filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y-%m-%d"
      header = "%t"
      permissions = 384
      locking = no
      escape_filenames = no
      log_packet_header = no
    }
    detail pre_proxy_log {
      filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y-%m-%d"
      header = "%t"
      permissions = 384
      locking = no
      escape_filenames = no
      log_packet_header = no
   }
    detail post_proxy_log {
      filename = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y-%m-%d"
      header = "%t"
      permissions = 384
      locking = no
      escape_filenames = no
      log_packet_header = no
    }
Loading dictionary rlm_digest
Loaded module "rlm_digest"
Loaded module "rlm_dhcpv4"
Loaded module "rlm_exec"
    exec echo {
      wait = yes
      program = "/bin/echo %{User-Name}"
      input_pairs = "request"
      output_pairs = "reply"
      shell_escape = yes
    }
Loaded module "rlm_escape"
    escape {
      safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
    }
    exec {
      wait = no
      input_pairs = "request"
      shell_escape = yes
      timeout = 10
    }
Loading dictionary rlm_expiration
Loaded module "rlm_expiration"
Loaded module "rlm_expr"
Loading dictionary rlm_files
Loaded module "rlm_files"
    files {
      filename = "/usr/local/etc/raddb/mods-config/files/authorize"
      acctusersfile = "/usr/local/etc/raddb/mods-config/files/accounting"
      preproxy_usersfile = "/usr/local/etc/raddb/mods-config/files/pre-proxy"
    }
Loaded module "rlm_linelog"
    linelog {
      destination = "file"
      delimiter = " "
      file {
        filename = "/usr/local/var/log/radius/linelog"
        permissions = 384
        escape_filenames = no
      }
      syslog {
        severity = "info"
      }
      unix {
      }
      tcp {
        port = 514
        timeout = 2.000000
      }
      udp {
        port = 514
        timeout = 2.000000
      }
    }
    linelog log_accounting {
      destination = "file"
      delimiter = " "
      file {
        filename = "/usr/local/var/log/radius/linelog-accounting"
        permissions = 384
        escape_filenames = no
      }
      syslog {
        severity = "info"
      }
      unix {
      }
      tcp {
        timeout = 1000.000000
      }
      udp {
        timeout = 1000.000000
      }
    }
Loading dictionary rlm_logintime
Loaded module "rlm_logintime"
    logintime {
      minimum_timeout = 60
    }
Loaded module "rlm_mschap"
    mschap {
      use_mppe = yes
      require_encryption = no
      require_strong = no
      with_ntdomain_hack = yes
      passchange {
      }
      allow_retry = yes
    }
    exec ntlm_auth {
      wait = yes
      program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}"
      shell_escape = yes
    }
Loading dictionary rlm_pap
Loaded module "rlm_pap"
    pap {
      normalise = yes
    }
Loading dictionary rlm_passwd
Loaded module "rlm_passwd"
    passwd etc_passwd {
      filename = "/etc/passwd"
      format = "*User-Name:Crypt-Password:"
      delimiter = ":"
      ignore_nislike = no
      ignore_empty = yes
      allow_multiple_keys = no
      hash_size = 100
    }
Loading dictionary rlm_radius
Loaded module "rlm_radius"
    radius {
      transport = udp
Loading dictionary rlm_radius_udp
Loaded module "rlm_radius_udp"
      udp {
        ipaddr = 127.0.0.1
        port = 1812
        secret = "testing123"
        max_packet_size = 4096
      }
      type = Access-Request
      type = Accounting-Request
      status_checks {
        type = Status-Server
      }
      max_connections = 32
      max_attributes = 255
      connection {
        connect_timeout = 5.000000
        reconnect_delay = 5.000000
        idle_timeout = 5.000000
        zombie_period = 10.000000
      }
      Access-Request {
        initial_retransmission_time = 2
        maximum_retransmission_time = 16
        maximum_retransmission_count = 2
        maximum_retransmission_duration = 30
      }
      Accounting-Request {
        initial_retransmission_time = 2
        maximum_retransmission_time = 16
        maximum_retransmission_count = 5
        maximum_retransmission_duration = 30
      }
      Status-Server {
        initial_retransmission_time = 2
        maximum_retransmission_time = 16
        maximum_retransmission_count = 5
        maximum_retransmission_duration = 30
      }
    }
Loading dictionary rlm_radutmp
Loaded module "rlm_radutmp"
    radutmp {
      filename = "/usr/local/var/log/radius/radutmp"
      username = "%{User-Name}"
      case_sensitive = yes
      check_with_nas = yes
      permissions = 384
      caller_id = yes
    }
    radutmp sradutmp {
      filename = "/usr/local/var/log/radius/sradutmp"
      username = "%{User-Name}"
      case_sensitive = yes
      check_with_nas = yes
      permissions = 420
      caller_id = no
    }
Loading dictionary rlm_stats
Loaded module "rlm_stats"
    stats {
    }
Loading dictionary rlm_unix
Loaded module "rlm_unix"
    unix {
      radwtmp = "/usr/local/var/log/radius/radwtmp"
    }
Creating attribute Unix-Group
Loading dictionary rlm_unpack
Loaded module "rlm_unpack"
Loaded module "rlm_utf8"
libfreeradius-redis: libhiredis version: 0.12.1
Loading dictionary rlm_redis_ippool
Loaded module "rlm_redis_ippool"
    redis_ippool {
      copy_on_update = yes
      redis {
        server = "devstack08-db-eval1-0001-001.oovb0g.0001.usw2.cache.amazonaws.com"
        port = 6379
        database = 0
       max_nodes = 20
        max_alt = 3
        max_redirects = 2
      }
    }
libfreeradius-redis: libhiredis version: 0.12.1
Loaded module "rlm_redis"
    redis {
      server = "devstack08-db-eval1-0001-001.oovb0g.0001.usw2.cache.amazonaws.com"
      port = 6379
      database = 0
      max_nodes = 20
      max_alt = 3
      max_redirects = 2
    }
  instantiate {
  }
} # modules
#### Instantiating listeners ####
Compiling policies in server dhcp { ... }
compiling - recv DHCP-Discover {...}
compiling - recv DHCP-Request {...}
compiling - recv DHCP-Decline {...}
compiling - recv DHCP-Inform {...}
compiling - recv DHCP-Release {...}
compiling - recv DHCP-Lease-Query {...}
#### Instantiating modules ####
Instantiating module "attr_filter.access_challenge"
Reading file /usr/local/etc/raddb/mods-config/attr_filter/access_challenge
Instantiating module "attr_filter.access_reject"
Reading file /usr/local/etc/raddb/mods-config/attr_filter/access_reject
Instantiating module "attr_filter.accounting_response"
Reading file /usr/local/etc/raddb/mods-config/attr_filter/accounting_response
Instantiating module "attr_filter.post-proxy"
Reading file /usr/local/etc/raddb/mods-config/attr_filter/post-proxy
Instantiating module "attr_filter.pre-proxy"
Reading file /usr/local/etc/raddb/mods-config/attr_filter/pre-proxy
Instantiating module "auth_log"
rlm_detail (auth_log) - 'User-Password' suppressed, will not appear in detail output
Instantiating module "cache_eap"
Loaded module "rlm_cache_rbtree"
Instantiating module "detail"
Instantiating module "etc_passwd"
Instantiating module "expiration"
Instantiating module "fail"
Instantiating module "files"
Reading file /usr/local/etc/raddb/mods-config/files/authorize
Reading file /usr/local/etc/raddb/mods-config/files/accounting
Reading file /usr/local/etc/raddb/mods-config/files/pre-proxy
Instantiating module "handled"
Instantiating module "invalid"
Instantiating module "linelog"
Instantiating module "log_accounting"
Instantiating module "logintime"
Instantiating module "mschap"
mschap: using internal authentication
Instantiating module "noop"
Instantiating module "notfound"
Instantiating module "ok"
Instantiating module "post_proxy_log"
Instantiating module "pre_proxy_log"
Instantiating module "radius"
Instantiating module "redis"
rlm_redis (redis) [1] - Initialising connection pool
      pool {
        start = 4
        min = 4
        max = 4
        max_pending = 0
        spare = 1
        uses = 0
        lifetime = 86400
        cleanup_interval = 300
        idle_timeout = 600
        connect_timeout = 3.000000
        held_trigger_min = 0.000000
        held_trigger_max = 0.500000
        retry_delay = 30
        spread = no
      }
rlm_redis (redis) [1] - Ignoring "spare = 1", forcing to "spare = 0"
rlm_redis (redis) [1] - Opening additional connection (0), 1 of 4 pending slots used
rlm_redis (redis) [1]: Connecting node to 10.43.17.86:6379
rlm_redis (redis) [1] - Opening additional connection (1), 1 of 3 pending slots used
rlm_redis (redis) [1]: Connecting node to 10.43.17.86:6379
rlm_redis (redis) [1] - Opening additional connection (2), 1 of 2 pending slots used
rlm_redis (redis) [1]: Connecting node to 10.43.17.86:6379
rlm_redis (redis) [1] - Opening additional connection (3), 1 of 1 pending slots used
rlm_redis (redis) [1]: Connecting node to 10.43.17.86:6379
rlm_redis (redis) [1] - Reserved connection (3)
rlm_redis (redis) [1] - Released connection (3)
rlm_redis (redis): Cluster map consists of 1 key ranges
rlm_redis (redis): 0 - keys 0-16383
rlm_redis (redis):  master: 10.43.17.86:6379
rlm_redis (redis):  slave0: 10.43.16.148:6379
rlm_redis (redis):  slave1: 10.43.16.109:6379
rlm_redis (redis) [2] - Initialising connection pool
     pool {
        start = 4
        min = 4
        max = 4
        max_pending = 0
        spare = 1
        uses = 0
        lifetime = 86400
        cleanup_interval = 300
        idle_timeout = 600
        connect_timeout = 3.000000
        held_trigger_min = 0.000000
        held_trigger_max = 0.500000
        retry_delay = 30
        spread = no
      }
rlm_redis (redis) [2] - Ignoring "spare = 1", forcing to "spare = 0"
rlm_redis (redis) [2] - Opening additional connection (0), 1 of 4 pending slots used
rlm_redis (redis) [2]: Connecting node to 10.43.16.148:6379
rlm_redis (redis) [2] - Opening additional connection (1), 1 of 3 pending slots used
rlm_redis (redis) [2]: Connecting node to 10.43.16.148:6379
rlm_redis (redis) [2] - Opening additional connection (2), 1 of 2 pending slots used
rlm_redis (redis) [2]: Connecting node to 10.43.16.148:6379
rlm_redis (redis) [2] - Opening additional connection (3), 1 of 1 pending slots used
rlm_redis (redis) [2]: Connecting node to 10.43.16.148:6379
rlm_redis (redis) [3] - Initialising connection pool
      pool {
        start = 4
        min = 4
        max = 4
        max_pending = 0
        spare = 1
        uses = 0
        lifetime = 86400
        cleanup_interval = 300
        idle_timeout = 600
        connect_timeout = 3.000000
        held_trigger_min = 0.000000
        held_trigger_max = 0.500000
        retry_delay = 30
        spread = no
      }
rlm_redis (redis) [3] - Ignoring "spare = 1", forcing to "spare = 0"
rlm_redis (redis) [3] - Opening additional connection (0), 1 of 4 pending slots used
rlm_redis (redis) [3]: Connecting node to 10.43.16.109:6379
rlm_redis (redis) [3] - Opening additional connection (1), 1 of 3 pending slots used
rlm_redis (redis) [3]: Connecting node to 10.43.16.109:6379
rlm_redis (redis) [3] - Opening additional connection (2), 1 of 2 pending slots used
rlm_redis (redis) [3]: Connecting node to 10.43.16.109:6379
rlm_redis (redis) [3] - Opening additional connection (3), 1 of 1 pending slots used
rlm_redis (redis) [3]: Connecting node to 10.43.16.109:6379
Instantiating module "redis_ippool"
rlm_redis (redis) [1] - Initialising connection pool
        pool {
          start = 0
          min = 4
          max = 4
          max_pending = 0
          spare = 1
          uses = 0
          lifetime = 0
          cleanup_interval = 30
          idle_timeout = 60
          connect_timeout = 3.000000
          held_trigger_min = 0.000000
          held_trigger_max = 0.500000
          retry_delay = 30
          spread = no
        }
rlm_redis (redis) [1] - Ignoring "spare = 1", forcing to "spare = 0"
rlm_redis (redis) [1] - 0 of 0 connections in use.  You  may need to increase "spare"
rlm_redis (redis) [1] - Opening additional connection (0), 1 of 4 pending slots used
rlm_redis (redis) [1]: Connecting node to 10.43.17.86:6379
rlm_redis (redis) [1] - Reserved connection (0)
rlm_redis (redis) [1] - Released connection (0)
rlm_redis (redis) [1] - Need 3 more connections to reach min connections (4)
rlm_redis (redis) [1] - Opening additional connection (1), 1 of 3 pending slots used
rlm_redis (redis) [1]: Connecting node to 10.43.17.86:6379
Instantiating module "reject"
Instantiating module "reply_log"
Instantiating module "stats"
Instantiating module "updated"
Instantiating module "userlock"
[1] radius - Connection initialising
[1] radius - Connection initialised
Scheduler created in single-threaded mode
#### Opening listener interfaces ####
Listening on dhcpv4 address proto_dhcpv4_udp server 10.43.16.207 port 67 bound to virtual server dhcp
Waking up in 4.9 seconds.
radius - Connection open - proto udp local 0.0.0.0 port 45078 remote 127.0.0.1 port 1812
radius - Allocated Status-Server ID 0 for status checks on connection proto udp local 0.0.0.0 port 45078 remote 127.0.0.1 port 1812
radius - Setting idle timeout to +5.000000 for connection proto udp local 0.0.0.0 port 45078 remote 127.0.0.1 port 1812
[1] radius - Connection established
Waking up in 4.9 seconds.
Waking up in 4.9 seconds.
radius - Idle timeout for connection proto udp local 0.0.0.0 port 45078 remote 127.0.0.1 port 1812
[1] radius - Closing connection (25)
radius - Connection closed - proto udp local 0.0.0.0 port 45078 remote 127.0.0.1 port 1812
Ready to process requests
proto_dhcpv4_udp - Received DHCP-Discover XID 00000000 length 310 proto_dhcpv4_udp server 10.43.16.207 port 67
Network received packet size 310
Resetting worker 30 cleanup timer to +0s
(0)  running request
(0)  Received DHCP-Discover XID 00000000 from 10.43.18.94:67 to 10.43.16.207:67 via eth0
(0)    &DHCP-Opcode = Client-Message
(0)    &DHCP-Hardware-Type = Ethernet
(0)    &DHCP-Hardware-Address-Length = 6
(0)    &DHCP-Hop-Count = 1
(0)    &DHCP-Transaction-Id = 0
(0)    &DHCP-Number-of-Seconds = 0
(0)    &DHCP-Flags = 0
(0)    &DHCP-Client-IP-Address = 10.43.18.94
(0)    &DHCP-Your-IP-Address = 0.0.0.0
(0)    &DHCP-Server-IP-Address = 0.0.0.0
(0)    &DHCP-Gateway-IP-Address = 10.43.18.94
(0)    &DHCP-Client-Hardware-Address = 00:a0:bc:00:00:02
(0)    &DHCP-Message-Type = DHCP-Discover
(0)    &DHCP-DHCP-Server-Identifier = 10.43.18.92
(0)    &DHCP-Client-Identifier = 0x0100a1bc000001
(0)    &DHCP-Subscriber-Id = "00a0bc000001@aut.res.viasat.com"
(0)    &DHCP-Relay-Remote-Id = 0x00a0bc000002
(0)    &DHCP-Relay-Circuit-Id = 0x000000222066
(0)  Running 'recv DHCP-Discover' from file /usr/local/etc/raddb/sites-enabled/dhcp
(0)  recv DHCP-Discover {
(0)    update reply {
(0)      DHCP-Message-Type = DHCP-Offer
(0)    } # update reply (noop)
(0)    update reply {
(0)      &DHCP-Subnet-Mask = 255.255.255.0
(0)      &DHCP-Router-Address = 192.0.2.1
(0)      &DHCP-DHCP-Server-Identifier = 192.0.2.1
(0)    } # update reply (noop)
(0)    update control {
(0)      &Pool-Name := "VSAT-UT"
(0)    } # update control (noop)
(0)    redis_ippool - Allocating lease from pool "VSAT-UT", to "00:a0:bc:00:00:02", expires in 120s
(0)    redis_ippool - Reserved connection (1)
(0)    redis_ippool - [1] >>> Sending command(s) to 10.43.17.86:6379
(0)    redis_ippool - [1] <<< Returned: success
(0)    redis_ippool - Released connection (1)
(0)    redis_ippool - Need 2 more connections to reach min connections (4)
(0)    redis_ippool - Opening additional connection (2), 1 of 2 pending slots used
rlm_redis (redis) [1]: Connecting node to 10.43.17.86:6379
(0)    redis_ippool - &reply:DHCP-Your-IP-Address := 10.88.64.104
(0)    redis_ippool - &reply:DHCP-IP-Address-Lease-Time := 120
(0)    redis_ippool - IP address lease allocated
(0)    redis_ippool (updated)
(0)    ok (ok)
(0)  } # recv DHCP-Discover (updated)
(0)  Sent DHCP-Offer XID 00000000 from 10.43.16.207:67 to 10.43.18.94:67 via eth0
(0)    &DHCP-Message-Type = DHCP-Offer
(0)    &DHCP-Subnet-Mask = 255.255.255.0
(0)    &DHCP-Router-Address = 192.0.2.1
(0)    &DHCP-DHCP-Server-Identifier = 192.0.2.1
(0)    &DHCP-IP-Address-Lease-Time := 120
(0)  done request
(0)  finished request.
Ready to process requests
Reply will be unicast to CIADDR from original packet.
proto_dhcpv4_udp - cleaning up ID 1
Ready to process requests
proto_dhcpv4_udp - Received DHCP-Request XID 00000000 length 316 proto_dhcpv4_udp server 10.43.16.207 port 67
Network received packet size 316
Resetting worker 30 cleanup timer to +0s
(1)  running request
(1)  Received DHCP-Request XID 00000000 from 10.43.18.94:67 to 10.43.16.207:67 via eth0
(1)    &DHCP-Opcode = Client-Message
(1)    &DHCP-Hardware-Type = Ethernet
(1)    &DHCP-Hardware-Address-Length = 6
(1)    &DHCP-Hop-Count = 1
(1)    &DHCP-Transaction-Id = 0
(1)    &DHCP-Number-of-Seconds = 0
(1)    &DHCP-Flags = 0
(1)    &DHCP-Client-IP-Address = 10.43.18.94
(1)    &DHCP-Your-IP-Address = 0.0.0.0
(1)    &DHCP-Server-IP-Address = 0.0.0.0
(1)    &DHCP-Gateway-IP-Address = 10.43.18.94
(1)    &DHCP-Client-Hardware-Address = 00:a0:bc:00:00:02
(1)    &DHCP-Requested-IP-Address = 10.88.64.104
(1)    &DHCP-Message-Type = DHCP-Request
(1)    &DHCP-DHCP-Server-Identifier = 10.43.18.92
(1)    &DHCP-Client-Identifier = 0x0100a1bc000001
(1)    &DHCP-Subscriber-Id = "00a0bc000001@aut.res.viasat.com"
(1)    &DHCP-Relay-Remote-Id = 0x00a0bc000002
(1)    &DHCP-Relay-Circuit-Id = 0x000000222066
(1)  Running 'recv DHCP-Request' from file /usr/local/etc/raddb/sites-enabled/dhcp
(1)  recv DHCP-Request {
(1)    update reply {
(1)      &DHCP-Message-Type = DHCP-Ack
(1)    } # update reply (noop)
(1)    update reply {
(1)      &DHCP-Subnet-Mask = 255.255.255.0
(1)      &DHCP-Router-Address = 192.0.2.1
(1)      &DHCP-DHCP-Server-Identifier = 192.0.2.1
(1)    } # update reply (noop)
(1)    update control {
(1)      &Pool-Name := "VSAT-UT"
(1)    } # update control (noop)
(1)    redis_ippool - Allocating lease from pool "VSAT-UT", to "00:a0:bc:00:00:02", expires in 120s
(1)    redis_ippool - Reserved connection (2)
(1)    redis_ippool - [1] >>> Sending command(s) to 10.43.17.86:6379
(1)    redis_ippool - [1] <<< Returned: success
(1)    redis_ippool - Released connection (2)
(1)    redis_ippool - &reply:DHCP-Your-IP-Address := 10.88.64.104
(1)    redis_ippool - &reply:DHCP-IP-Address-Lease-Time := 120
(1)    redis_ippool - IP address lease allocated
(1)    redis_ippool (updated)
(1)    ok (ok)
(1)  } # recv DHCP-Request (updated)
(1)  Sent DHCP-Ack XID 00000000 from 10.43.16.207:67 to 10.43.18.94:67 via eth0
(1)    &DHCP-Message-Type = DHCP-Ack
(1)    &DHCP-Subnet-Mask = 255.255.255.0
(1)    &DHCP-Router-Address = 192.0.2.1
(1)    &DHCP-DHCP-Server-Identifier = 192.0.2.1
(1)    &DHCP-IP-Address-Lease-Time := 120
(1)  done request
(1)  finished request.
Ready to process requests
Reply will be unicast to CIADDR from original packet.
proto_dhcpv4_udp - cleaning up ID 1
Ready to process requests

Regards,
Nagamani Chinnapaiyan

redis_ippool module doesnot process lease_time in ack

Chinnapaiyan, Nagamani