TXID mismatch between DHCP Request-Offer (devel version)

classic Classic list List threaded Threaded
5 messages Options
| Threaded
Open this post in threaded view
|

TXID mismatch between DHCP Request-Offer (devel version)

Chinnapaiyan, Nagamani
Hi,
I am trying to test redis backend for freeradius dhcp server(master branch, latest git commit hash: 71ce6ae15b6ad69a0d58260f6befa7973b1d822a).

The server was able to chose ip from redis backend(redis_ippool module). But when sending back offer to the client it changes the transaction id(which should not be changed).  The client drops the packet as the txid doesnot match. Attached the pcap for reference.
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/eap
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/eap_inner
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/pam
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/soh
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/mac2ip
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/sql
Debug : including configuration file /usr/local/etc/raddb/mods-config/sql/driver/mysql
Debug : including configuration file /usr/local/etc/raddb/mods-config/sql/main/mysql/queries.conf
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/redis
Debug : including configuration file /usr/local/etc/raddb/mods-enabled/redis_ippool
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/filter
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 files in directory "/usr/local/etc/raddb/sites-enabled/"
Debug : including configuration file /usr/local/etc/raddb/sites-enabled/default
Debug : Loading dictionary proto_radius
Info  : Loaded module "proto_radius"
Debug : including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel
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 default {
Debug :     namespace = "radius"
Debug :     listen {
Debug :       type = Access-Request
Debug : Loading dictionary proto_radius_auth
Info  : Loaded module "proto_radius_auth"
Debug :       Access-Request {
Debug :         log {
Debug :           stripped_names = no
Debug :           auth = no
Debug :           auth_badpass = no
Debug :           auth_goodpass = no
Debug :           msg_denied = "You are already logged in - access denied"
Debug :         }
Debug :         session {
Debug :           timeout = 15
Debug :           max = 4096
Debug :         }
Debug :       }
Debug :       type = Status-Server
Debug : Loading dictionary proto_radius_status
Info  : Loaded module "proto_radius_status"
Debug :       transport = udp
Info  : Loaded module "proto_radius_udp"
Debug :       udp {
Debug :         ipaddr = *
Debug :         port = 1812
Debug :         networks {
Debug :           allow = 127/8
Debug :           allow = 192.0.2/24
Debug :         }
Debug :         max_packet_size = 4096
Debug :         max_attributes = 255
Debug :       }
Debug :       limit {
Debug :         cleanup_delay = 5.000000
Debug :         idle_timeout = 60.000000
Debug :         nak_lifetime = 30.000000
Debug :         max_connections = 256
Debug :         max_clients = 256
Debug :         max_pending_packets = 256
Debug :       }
Debug :       priority {
Debug :         Access-Request = high
Debug :         Accounting-Request = low
Debug :         CoA-Request = normal
Debug :         Disconnect-Request = low
Debug :         Status-Server = now
Debug :       }
Debug :     }
Debug :     listen {
Debug :       type = Accounting-Request
Debug : Loading dictionary proto_radius_acct
Info  : Loaded module "proto_radius_acct"
Debug :       transport = udp
Debug :       udp {
Debug :         ipaddr = *
Debug :         port = 1813
Debug :         networks {
Debug :         }
Debug :         max_packet_size = 4096
Debug :         max_attributes = 255
Debug :       }
Debug :       limit {
Debug :         cleanup_delay = 5.000000
Debug :         idle_timeout = 30.000000
Debug :         nak_lifetime = 30.000000
Debug :         max_connections = 1024
Debug :         max_clients = 256
Debug :         max_pending_packets = 256
Debug :       }
Debug :       priority {
Debug :         Access-Request = high
Debug :         Accounting-Request = low
Debug :         CoA-Request = normal
Debug :         Disconnect-Request = low
Debug :         Status-Server = now
Debug :       }
Debug :     }
Debug :   }
Debug :   server inner-tunnel {
Debug :     namespace = "radius"
Debug :     listen {
Debug :       type = Access-Request
Debug :       Access-Request {
Debug :         log {
Debug :           stripped_names = no
Debug :           auth = no
Debug :           auth_badpass = no
Debug :           auth_goodpass = no
Debug :           msg_denied = "You are already logged in - access denied"
Debug :         }
Debug :         session {
Debug :           timeout = 15
Debug :           max = 4096
Debug :         }
Debug :       }
Debug :       transport = udp
Debug :       udp {
Debug :         ipaddr = 127.0.0.1
Debug :         port = 18120
Debug :         networks {
Debug :         }
Debug :         max_packet_size = 4096
Debug :         max_attributes = 255
Debug :       }
Debug :       limit {
Debug :         cleanup_delay = 5.000000
Debug :         idle_timeout = 30.000000
Debug :         nak_lifetime = 30.000000
Debug :         max_connections = 1024
Debug :         max_clients = 256
Debug :         max_pending_packets = 256
Debug :       }
Debug :       priority {
Debug :         Access-Request = high
Debug :         Accounting-Request = low
Debug :         CoA-Request = normal
Debug :         Disconnect-Request = low
Debug :         Status-Server = now
Debug :       }
Debug :     }
Debug :   }
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.18.92
Debug :         src_ipaddr = 10.43.18.92
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 private-network-1 {
    ipaddr = 10.43.18.0/24
    require_message_authenticator = no
    secret = <<< secret >>>
    limit {
      max_connections = 16
      lifetime = 0
      idle_timeout = 30
    }
  }
Debugger not attached
#### Bootstrapping listeners ####
Creating Auth-Type = pap
Creating Auth-Type = chap
Creating Auth-Type = mschap
Creating Auth-Type = digest
Creating Auth-Type = pam
Creating Auth-Type = ldap
Creating Auth-Type = eap
    client localhost {
      ipaddr = 192.0.2.1
      require_message_authenticator = no
      secret = <<< secret >>>
      shortname = "sample"
      limit {
        max_connections = 16
        lifetime = 0
        idle_timeout = 30
      }
    }
#### 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"
Loading dictionary rlm_eap
Loaded module "rlm_eap"
    eap {
      default_eap_type = md5
      type = md5
Loading dictionary rlm_eap_md5
Loaded module "rlm_eap_md5"
      type = gtc
Loading dictionary rlm_eap_gtc
Loaded module "rlm_eap_gtc"
      gtc {
        challenge = "Password: "
        auth_type = PAP
      }
      type = tls
Loading dictionary rlm_eap_tls
Loaded module "rlm_eap_tls"
      tls {
        tls = "tls-common"
        require_client_cert = yes
        include_length = yes
      }
      type = ttls
Loading dictionary rlm_eap_ttls
Loaded module "rlm_eap_ttls"
      ttls {
        tls = "tls-common"
        virtual_server = "inner-tunnel"
        include_length = yes
        require_client_cert = no
      }
      type = mschapv2
Loading dictionary rlm_eap_mschapv2
Loaded module "rlm_eap_mschapv2"
      mschapv2 {
        with_ntdomain_hack = no
        auth_type = mschap
        send_error = no
      }
      type = peap
Loading dictionary rlm_eap_peap
Loaded module "rlm_eap_peap"
      peap {
        tls = "tls-common"
        proxy_tunneled_request_as_eap = yes
        virtual_server = "inner-tunnel"
        soh = no
        require_client_cert = no
      }
      type = sim
Loading dictionary rlm_eap_sim
Loaded module "rlm_eap_sim"
      sim {
        protected_success = no
      }
      ignore_unknown_eap_types = no
      cisco_accounting_username_bug = no
    }
    eap inner-eap {
      default_eap_type = mschapv2
      type = md5
      type = gtc
      gtc {
        challenge = "Password: "
        auth_type = PAP
      }
      type = mschapv2
      mschapv2 {
        with_ntdomain_hack = no
        auth_type = mschap
        send_error = no
      }
      type = tls
      tls {
        tls = "tls-peer"
        require_client_cert = yes
        include_length = yes
      }
      ignore_unknown_eap_types = no
      cisco_accounting_username_bug = no
    }
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_pam
Loaded module "rlm_pam"
    pam {
      pam_auth = "radiusd"
    }
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
    }
Loading dictionary rlm_soh
Loaded module "rlm_soh"
    soh {
      dhcp = 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"
    passwd mac2ip {
      filename = "/usr/local/etc/raddb/mods-config/passwd/mac2ip"
      format = "*DHCP-Client-Hardware-Address:=DHCP-Your-IP-Address"
      delimiter = ","
      ignore_nislike = yes
      ignore_empty = yes
      allow_multiple_keys = no
      hash_size = 100
    }
Loading dictionary rlm_sql
Loaded module "rlm_sql"
    sql {
      driver = "rlm_sql_mysql"
      server = ""
      port = 0
      login = "root"
      password = <<< secret >>>
      radius_db = "radius"
      read_groups = yes
      read_profiles = yes
      sql_user_name = "%{User-Name}"
      group_attribute = "sql-Group"
      default_user_profile = ""
      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"
      group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority"
      safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
      accounting {
        reference = "%{tolower:type.%{Acct-Status-Type}.query}"
        type {
          accounting-on {
            query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress   = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})"
          }
          accounting-off {
            query = "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = '%{integer:Event-Timestamp}' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = '%{%{Acct-Terminate-Cause}:-NAS-Reboot}' WHERE acctstoptime IS NULL AND nasipaddress   = '%{NAS-IP-Address}' AND acctstarttime <= FROM_UNIXTIME(%{integer:Event-Timestamp})"
          }
          start {
            query = "INSERT INTO radacct (acctsessionid,                     acctuniqueid,                  username, realm,              nasipaddress,                  nasportid, nasporttype,                acctstarttime,                  acctupdatetime, acctstoptime,                  acctsessiontime,               acctauthentic, connectinfo_start,              connectinfo_stop,           acctinputoctets, acctoutputoctets,           calledstationid, callingstationid, acctterminatecause,       servicetype,                     framedprotocol, framedipaddress,              framedipv6address,       framedipv6prefix, framedinterfaceid,         delegatedipv6prefix) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', FROM_UNIXTIME(%{integer:Event-Timestamp}), FROM_UNIXTIME(%{integer:Event-Timestamp}), NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Framed-IPv6-Address}', '%{Framed-IPv6-Prefix}', '%{Framed-Interface-Id}', '%{Delegated-IPv6-Prefix}')"
            query = "UPDATE radacct SET acctstarttime          = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctupdatetime = FROM_UNIXTIME(%{integer:Event-Timestamp}), connectinfo_start = '%{Connect-Info}' WHERE acctuniqueid = '%{Acct-Unique-Session-Id}'"
          }
          interim-update {
            query = "UPDATE radacct SET acctupdatetime  = (@acctupdatetime_old:=acctupdatetime), acctupdatetime  = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctinterval    = %{integer:Event-Timestamp} - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '%{Framed-IP-Address}', framedipv6address = '%{Framed-IPv6-Address}', framedipv6prefix = '%{Framed-IPv6-Prefix}', framedinterfaceid = '%{Framed-Interface-Id}', delegatedipv6prefix = '%{Delegated-IPv6-Prefix}', acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctuniqueid = '%{Acct-Unique-Session-Id}'"
            query = "INSERT INTO radacct (acctsessionid,                     acctuniqueid,                  username, realm,               nasipaddress,                  nasportid, nasporttype,                acctstarttime,                  acctupdatetime, acctstoptime,                  acctsessiontime,               acctauthentic, connectinfo_start,              connectinfo_stop,           acctinputoctets, acctoutputoctets,           calledstationid, callingstationid, acctterminatecause,       servicetype,                     framedprotocol, framedipaddress,              framedipv6address,       framedipv6prefix, framedinterfaceid,         delegatedipv6prefix) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', FROM_UNIXTIME(%{integer:Event-Timestamp} - %{%{Acct-Session-Time}:-0}), FROM_UNIXTIME(%{integer:Event-Timestamp}), NULL, %{%{Acct-Session-Time}:-NULL}, '%{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}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Framed-IPv6-Address}', '%{Framed-IPv6-Prefix}', '%{Framed-Interface-Id}', '%{Delegated-IPv6-Prefix}')"
          }
          stop {
            query = "UPDATE radacct SET acctstoptime           = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', connectinfo_stop = '%{Connect-Info}' WHERE acctuniqueid = '%{Acct-Unique-Session-Id}'"
            query = "INSERT INTO radacct (acctsessionid,                     acctuniqueid,                  username, realm,               nasipaddress,                  nasportid, nasporttype,                acctstarttime,                  acctupdatetime, acctstoptime,                  acctsessiontime,               acctauthentic, connectinfo_start,              connectinfo_stop,           acctinputoctets, acctoutputoctets,           calledstationid, callingstationid, acctterminatecause,       servicetype,                     framedprotocol, framedipaddress,              framedipv6address,       framedipv6prefix, framedinterfaceid,         delegatedipv6prefix) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-ID}:-%{NAS-Port}}', '%{NAS-Port-Type}', FROM_UNIXTIME(%{integer:Event-Timestamp} - %{%{Acct-Session-Time}:-0}), FROM_UNIXTIME(%{integer:Event-Timestamp}), FROM_UNIXTIME(%{integer:Event-Timestamp}), %{%{Acct-Session-Time}:-NULL}, '%{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}', '%{Framed-IPv6-Address}', '%{Framed-IPv6-Prefix}', '%{Framed-Interface-Id}', '%{Delegated-IPv6-Prefix}')"
          }
        }
      }
      post-auth {
        reference = ".query"
        query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')"
      }
    }
rlm_sql_mysql - libmysql version: 5.6.41
Loaded module "rlm_sql_mysql"
      mysql {
        tls {
        }
        warnings = "auto"
      }
Creating attribute sql-Group
libfreeradius-redis: libhiredis version: 0.12.1
Loaded module "rlm_redis"
    redis {
      server = "127.0.0.1"
      port = 6379
      database = 0
      max_nodes = 20
      max_alt = 3
      max_redirects = 2
    }
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 = "localhost"
        port = 6379
        database = 0
        max_nodes = 20
        max_alt = 3
        max_redirects = 2
      }
    }
  instantiate {
  }
} # modules
#### Instantiating listeners ####
Compiling policies in server default { ... }
compiling - recv Access-Request {...}
/usr/local/etc/raddb/sites-enabled/default[706]: Ignoring "ldap" (see mods-available/README.md)
compiling - recv Status-Server {...}
compiling - send Access-Challenge {...}
compiling - send Access-Accept {...}
compiling - send Access-Reject {...}
compiling - send Accounting-Response {...}
Compiling policies - authenticate pap {...}
Compiling policies - authenticate chap {...}
Compiling policies - authenticate mschap {...}
Compiling policies - authenticate digest {...}
Compiling policies - authenticate pam {...}
Compiling policies - authenticate ldap {...}
/usr/local/etc/raddb/sites-enabled/default[876]: Ignoring "ldap" (see mods-available/README.md)
Compiling policies - authenticate eap {...}
compiling - recv Accounting-Request {...}
/usr/local/etc/raddb/sites-enabled/default[520]: client localhost { ... } section is unused
Compiling policies in server inner-tunnel { ... }
compiling - recv Access-Request {...}
/usr/local/etc/raddb/sites-enabled/inner-tunnel[134]: Ignoring "ldap" (see mods-available/README.md)
compiling - send Access-Accept {...}
compiling - send Access-Reject {...}
Compiling policies - authenticate pap {...}
Compiling policies - authenticate chap {...}
Compiling policies - authenticate mschap {...}
Compiling policies - authenticate pam {...}
Compiling policies - authenticate eap {...}
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 "eap"
      tls-config tls-common {
        auto_chain = yes
        chain {
          format = pem
          certificate_file = "/usr/local/etc/raddb/certs/rsa/server.pem"
          private_key_password = <<< secret >>>
          private_key_file = "/usr/local/etc/raddb/certs/rsa/server.key"
          ca_file = "/usr/local/etc/raddb/certs/rsa/ca.pem"
          verify_mode = hard
          include_root_ca = no
        }
        chain {
          format = pem
          certificate_file = "/usr/local/etc/raddb/certs/ecc/server.pem"
          private_key_password = <<< secret >>>
          private_key_file = "/usr/local/etc/raddb/certs/ecc/server.key"
          ca_file = "/usr/local/etc/raddb/certs/ecc/ca.pem"
          verify_mode = hard
         include_root_ca = no
        }
        verify_depth = 0
        ca_path = "/usr/local/etc/raddb/certs"
        ca_file = "/usr/local/etc/raddb/certs/rsa/ca.pem"
        dh_file = "/usr/local/etc/raddb/certs/dh"
        fragment_size = 1024
        check_crl = no
        cipher_list = "DEFAULT"
        cipher_server_preference = yes
        allow_renegotiation = no
        ecdh_curve = "prime256v1"
        tls_min_version = 1.000000
        cache {
          lifetime = 86400
          verify = no
        }
        verify {
        }
        ocsp {
          enable = no
          override_cert_url = yes
          url = "http://127.0.0.1/ocsp/"
          use_nonce = yes
          timeout = 0
          softfail = no
        }
        staple {
          enable = no
          override_cert_url = yes
          url = "http://127.0.0.1/ocsp/"
          use_nonce = yes
          timeout = 0
          softfail = no
        }
      }
tls - Using cached TLS configuration from previous invocation
tls - Using cached TLS configuration from previous invocation
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 "inner-eap"
      tls-config tls-peer {
        auto_chain = yes
        chain {
          format = pem
          certificate_file = "/usr/local/etc/raddb/certs/rsa/server.pem"
          private_key_password = <<< secret >>>
          private_key_file = "/usr/local/etc/raddb/certs/rsa/server.key"
          ca_file = "/usr/local/etc/raddb/certs/rsa/ca.pem"
          verify_mode = hard
          include_root_ca = no
        }
        verify_depth = 0
        ca_path = "/usr/local/etc/raddb/certs"
        ca_file = "/usr/local/etc/raddb/certs/rsa/ca.pem"
        dh_file = "/usr/local/etc/raddb/certs/dh"
        fragment_size = 16384
        check_crl = no
        cipher_server_preference = yes
        allow_renegotiation = no
        ecdh_curve = "prime256v1"
        tls_min_version = 1.000000
        cache {
          lifetime = 86400
          verify = no
        }
        verify {
        }
        ocsp {
          enable = no
          override_cert_url = no
          use_nonce = yes
          timeout = 0
          softfail = no
        }
        staple {
          enable = no
          override_cert_url = no
          use_nonce = yes
          timeout = 0
          softfail = no
        }
      }
Instantiating module "invalid"
Instantiating module "linelog"
Instantiating module "log_accounting"
Instantiating module "logintime"
Instantiating module "mac2ip"
Instantiating module "mschap"
mschap: using internal authentication
Instantiating module "noop"
Instantiating module "notfound"
Instantiating module "ok"
Instantiating module "pam"
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 = 1
        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] - Opening additional connection (0), 1 of 4 pending slots used
rlm_redis (redis) [1]: Connecting node to 127.0.0.1:6379
rlm_redis (redis) [1] - Opening additional connection (1), 1 of 3 pending slots used
rlm_redis (redis) [1]: Connecting node to 127.0.0.1:6379
rlm_redis (redis) [1] - Opening additional connection (2), 1 of 2 pending slots used
rlm_redis (redis) [1]: Connecting node to 127.0.0.1:6379
rlm_redis (redis) [1] - Opening additional connection (3), 1 of 1 pending slots used
rlm_redis (redis) [1]: Connecting node to 127.0.0.1:6379
rlm_redis (redis) [1] - Reserved connection (3)
rlm_redis (redis): Bootstrap server "127.0.0.1" returned: ERR This instance has cluster support disabled
rlm_redis (redis) [1] - Released connection (3)
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 127.0.0.1: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 127.0.0.1:6379
Instantiating module "reject"
Instantiating module "reply_log"
Instantiating module "sql"
rlm_sql (sql) - Attempting to connect to database "radius"
rlm_sql (sql) - Initialising connection pool
      pool {
        start = 4
        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_sql (sql) - Ignoring "spare = 1", forcing to "spare = 0"
rlm_sql (sql) - Opening additional connection (0), 1 of 4 pending slots used
rlm_sql_mysql - Starting connect to MySQL server
rlm_sql_mysql - Connected to database 'radius' on Localhost via UNIX socket, server version 5.6.41, protocol version 10
rlm_sql (sql) - Opening additional connection (1), 1 of 3 pending slots used
rlm_sql_mysql - Starting connect to MySQL server
rlm_sql_mysql - Connected to database 'radius' on Localhost via UNIX socket, server version 5.6.41, protocol version 10
rlm_sql (sql) - Opening additional connection (2), 1 of 2 pending slots used
rlm_sql_mysql - Starting connect to MySQL server
rlm_sql_mysql - Connected to database 'radius' on Localhost via UNIX socket, server version 5.6.41, protocol version 10
rlm_sql (sql) - Opening additional connection (3), 1 of 1 pending slots used
rlm_sql_mysql - Starting connect to MySQL server
rlm_sql_mysql - Connected to database 'radius' on Localhost via UNIX socket, server version 5.6.41, protocol version 10
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 radius address proto_radius_udp server * port 1812 bound to virtual server default
Listening on radius address proto_radius_udp server * port 1813 bound to virtual server default
Listening on radius address proto_radius_udp server 127.0.0.1 port 18120 bound to virtual server inner-tunnel
Listening on dhcpv4 address proto_dhcpv4_udp server 10.43.18.92 port 67 bound to virtual server dhcp
Waking up in 4.9 seconds.
radius - Connection open - proto udp local 0.0.0.0 port 47661 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 47661 remote 127.0.0.1 port 1812
radius - Setting idle timeout to +5.000000 for connection proto udp local 0.0.0.0 port 47661 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 47661 remote 127.0.0.1 port 1812
[1] radius - Closing connection (21)
radius - Connection closed - proto udp local 0.0.0.0 port 47661 remote 127.0.0.1 port 1812
Ready to process requests
proto_dhcpv4_udp - Received DHCP-Discover XID 0000 length 259 proto_dhcpv4_udp server 10.43.18.92 port 67
Network received packet size 259
Resetting worker 30 cleanup timer to +0s
(0)  running request
(0)  Received DHCP-Discover ID 00000001
(0)    DHCP-Message-Type = DHCP-Discover
(0)    DHCP-DHCP-Server-Identifier = 10.43.18.92
(0)    DHCP-Client-Identifier = 0x0100a1bc000001
(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-Domain-Name-Server = 127.0.0.1
(0)      &DHCP-Subnet-Mask = 255.255.255.0
(0)      &DHCP-Router-Address = 10.43.18.92
(0)      &DHCP-IP-Address-Lease-Time = 86400
(0)      &DHCP-DHCP-Server-Identifier = 10.43.18.92
(0)    } # update reply (noop)
(0)    update control {
(0)      &Pool-Name := "local"
(0)    } # update control (noop)
(0)    redis_ippool - Allocating lease from pool "local", to "00:a1:bc:00:00:01", expires in 300s
(0)    redis_ippool - Closing connection (1): Hit idle_timeout, was idle for 70 seconds
(0)    redis_ippool - You probably need to lower "min"
(0)    redis_ippool - Closing connection (0): Hit idle_timeout, was idle for 70 seconds
(0)    redis_ippool - You probably need to lower "min"
(0)    redis_ippool - 0 of 0 connections in use.  You  may need to increase "spare"
(0)    redis_ippool - Opening additional connection (2), 1 of 4 pending slots used
rlm_redis (redis) [1]: Connecting node to 127.0.0.1:6379
(0)    redis_ippool - Reserved connection (2)
(0)    redis_ippool - [1] >>> Sending command(s) to 127.0.0.1:6379
(0)    redis_ippool - [1] <<< Returned: success
(0)    redis_ippool - Released connection (2)
(0)    redis_ippool - Need 3 more connections to reach min connections (4)
(0)    redis_ippool - Opening additional connection (3), 1 of 3 pending slots used
rlm_redis (redis) [1]: Connecting node to 127.0.0.1:6379
(0)    redis_ippool - &reply:DHCP-Your-IP-Address := 192.168.0.112
(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 code 2 Id 1 from 10.43.18.92:67 to 127.0.0.1:67 via lo length 0
(0)    &DHCP-Message-Type = DHCP-Offer
(0)    &DHCP-Domain-Name-Server = 127.0.0.1
(0)    &DHCP-Subnet-Mask = 255.255.255.0
(0)    &DHCP-Router-Address = 10.43.18.92
(0)    &DHCP-IP-Address-Lease-Time := 120
(0)    &DHCP-DHCP-Server-Identifier = 10.43.18.92
(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

Regards,
Nagamani Chinnapaiyan


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

dora_txid_mismatch_redis.pcap (1006 bytes) Download Attachment
| Threaded
Open this post in threaded view
|

Re: TXID mismatch between DHCP Request-Offer (devel version)

Alan DeKok-2
On Nov 21, 2018, at 1:52 AM, Chinnapaiyan, Nagamani <[hidden email]> wrote:
> I am trying to test redis backend for freeradius dhcp server(master branch, latest git commit hash: 71ce6ae15b6ad69a0d58260f6befa7973b1d822a).
>
> The server was able to chose ip from redis backend(redis_ippool module). But when sending back offer to the client it changes the transaction id(which should not be changed).  The client drops the packet as the txid doesnot match. Attached the pcap for reference.

  I've pushed some fixes which should help.

  Alan DeKok.



-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
| Threaded
Open this post in threaded view
|

Re: TXID mismatch between DHCP Request-Offer (devel version)

Chinnapaiyan, Nagamani
In reply to this post by Chinnapaiyan, Nagamani
Thanks for the quick fix. Now TXID is fixed. But the server responds with OFFER even for Request message.
Attached the pcap for your reference.

Debug output for Redis_ippool:

Ready to process requests

proto_dhcpv4_udp - Received DHCP-Discover XID 00000000 length 259 proto_dhcpv4_udp server 10.43.18.92 port 67

Network received packet size 259

Resetting worker 30 cleanup timer to +0s

(0)  running request

(0)  Received DHCP-Discover XID 00000000 from 127.0.0.1:67 to 10.43.18.92:67 via lo

(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 = 127.0.0.1

(0)    &DHCP-Your-IP-Address = 0.0.0.0

(0)    &DHCP-Server-IP-Address = 0.0.0.0

(0)    &DHCP-Gateway-IP-Address = 127.0.0.1

(0)    &DHCP-Client-Hardware-Address = 00:a1:bc:00:00:01

(0)    &DHCP-Message-Type = DHCP-Discover

(0)    &DHCP-DHCP-Server-Identifier = 10.43.18.92

(0)    &DHCP-Client-Identifier = 0x0100a1bc000001

(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-Domain-Name-Server = 127.0.0.1

(0)      &DHCP-Subnet-Mask = 255.255.255.0

(0)      &DHCP-Router-Address = 10.43.18.92

(0)      &DHCP-IP-Address-Lease-Time = 86400

(0)      &DHCP-DHCP-Server-Identifier = 10.43.18.92

(0)    } # update reply (noop)

(0)    update control {

(0)      &Pool-Name := "local"

(0)    } # update control (noop)

(0)    redis_ippool - Allocating lease from pool "local", to "00:a1:bc:00:00:01", expires in 300s

(0)    redis_ippool - Reserved connection (1)

(0)    redis_ippool - [1] >>> Sending command(s) to 127.0.0.1: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 127.0.0.1:6379

(0)    redis_ippool - &reply:DHCP-Your-IP-Address := 192.168.0.122

(0)    redis_ippool - &reply:DHCP-IP-Address-Lease-Time := 300

(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.18.92:67 to 127.0.0.1:67 via lo

(0)    &DHCP-Message-Type = DHCP-Offer

(0)    &DHCP-Domain-Name-Server = 127.0.0.1

(0)    &DHCP-Subnet-Mask = 255.255.255.0

(0)    &DHCP-Router-Address = 10.43.18.92

(0)    &DHCP-IP-Address-Lease-Time := 300

(0)    &DHCP-DHCP-Server-Identifier = 10.43.18.92

(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 265 proto_dhcpv4_udp server 10.43.18.92 port 67

Network received packet size 265

Resetting worker 30 cleanup timer to +0s

(1)  running request

(1)  Received DHCP-Discover XID 00000000 from 127.0.0.1:67 to 10.43.18.92:67 via lo

(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 = 127.0.0.1

(1)    &DHCP-Your-IP-Address = 0.0.0.0

(1)    &DHCP-Server-IP-Address = 0.0.0.0

(1)    &DHCP-Gateway-IP-Address = 127.0.0.1

(1)    &DHCP-Client-Hardware-Address = 00:a1:bc:00:00:01

(1)    &DHCP-Requested-IP-Address = 192.168.0.122

(1)    &DHCP-Message-Type = DHCP-Request

(1)    &DHCP-DHCP-Server-Identifier = 10.43.18.92

(1)    &DHCP-Client-Identifier = 0x0100a1bc000001

(1)  Running 'recv DHCP-Discover' from file /usr/local/etc/raddb/sites-enabled/dhcp

(1)  recv DHCP-Discover {

(1)    update reply {

(1)      DHCP-Message-Type = DHCP-Offer

(1)    } # update reply (noop)

(1)    update reply {

(1)      &DHCP-Domain-Name-Server = 127.0.0.1

(1)      &DHCP-Subnet-Mask = 255.255.255.0

(1)      &DHCP-Router-Address = 10.43.18.92

(1)      &DHCP-IP-Address-Lease-Time = 86400

(1)      &DHCP-DHCP-Server-Identifier = 10.43.18.92

(1)    } # update reply (noop)

(1)    update control {

(1)      &Pool-Name := "local"

(1)    } # update control (noop)

(1)    redis_ippool - Allocating lease from pool "local", to "00:a1:bc:00:00:01", expires in 300s

(1)    redis_ippool - Reserved connection (2)

(1)    redis_ippool - [1] >>> Sending command(s) to 127.0.0.1:6379

(1)    redis_ippool - [1] <<< Returned: success

(1)    redis_ippool - Released connection (2)

(1)    redis_ippool - &reply:DHCP-Your-IP-Address := 192.168.0.122

(1)    redis_ippool - &reply:DHCP-IP-Address-Lease-Time := 300

(1)    redis_ippool - IP address lease allocated

(1)    redis_ippool (updated)

(1)    ok (ok)

(1)  } # recv DHCP-Discover (updated)

(1)  Sent DHCP-Offer XID 00000000 from 10.43.18.92:67 to 127.0.0.1:67 via lo

(1)    &DHCP-Message-Type = DHCP-Offer

(1)    &DHCP-Domain-Name-Server = 127.0.0.1

(1)    &DHCP-Subnet-Mask = 255.255.255.0

(1)    &DHCP-Router-Address = 10.43.18.92

(1)    &DHCP-IP-Address-Lease-Time := 300

(1)    &DHCP-DHCP-Server-Identifier = 10.43.18.92

(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
Debug output for mac2ip:

proto_dhcpv4_udp - Received DHCP-Discover XID 00000000 length 259 proto_dhcpv4_udp server 10.43.18.92 port 67

Network received packet size 259

Resetting worker 30 cleanup timer to +0s

(4)  running request

(4)  Received DHCP-Discover XID 00000000 from 127.0.0.1:67 to 10.43.18.92:67 via lo

(4)    &DHCP-Opcode = Client-Message

(4)    &DHCP-Hardware-Type = Ethernet

(4)    &DHCP-Hardware-Address-Length = 6

(4)    &DHCP-Hop-Count = 1

(4)    &DHCP-Transaction-Id = 0

(4)    &DHCP-Number-of-Seconds = 0

(4)    &DHCP-Flags = 0

(4)    &DHCP-Client-IP-Address = 127.0.0.1

(4)    &DHCP-Your-IP-Address = 0.0.0.0

(4)    &DHCP-Server-IP-Address = 0.0.0.0

(4)    &DHCP-Gateway-IP-Address = 127.0.0.1

(4)    &DHCP-Client-Hardware-Address = 00:a1:bc:00:00:01

(4)    &DHCP-Message-Type = DHCP-Discover

(4)    &DHCP-DHCP-Server-Identifier = 10.43.18.92

(4)    &DHCP-Client-Identifier = 0x0100a1bc000001

(4)  Running 'recv DHCP-Discover' from file /usr/local/etc/raddb/sites-enabled/dhcp

(4)  recv DHCP-Discover {

(4)    update reply {

(4)      DHCP-Message-Type = DHCP-Offer

(4)    } # update reply (noop)

(4)    update reply {

(4)      &DHCP-Domain-Name-Server = 127.0.0.1

(4)      &DHCP-Subnet-Mask = 255.255.255.0

(4)      &DHCP-Router-Address = 10.43.18.92

(4)      &DHCP-IP-Address-Lease-Time = 86400

(4)      &DHCP-DHCP-Server-Identifier = 10.43.18.92

(4)    } # update reply (noop)

(4)    mac2ip - Added DHCP-Your-IP-Address: '10.1.1.3' to reply_items

(4)    mac2ip (ok)

(4)    ok (ok)

(4)  } # recv DHCP-Discover (ok)

(4)  Sent DHCP-Offer XID 00000000 from 10.43.18.92:67 to 127.0.0.1:67 via lo

(4)    &DHCP-Message-Type = DHCP-Offer

(4)    &DHCP-Domain-Name-Server = 127.0.0.1

(4)    &DHCP-Subnet-Mask = 255.255.255.0

(4)    &DHCP-Router-Address = 10.43.18.92

(4)    &DHCP-IP-Address-Lease-Time = 86400

(4)    &DHCP-DHCP-Server-Identifier = 10.43.18.92

(4)  done request

(4)  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 265 proto_dhcpv4_udp server 10.43.18.92 port 67

Network received packet size 265

Resetting worker 30 cleanup timer to +0s

(5)  running request

(5)  Received DHCP-Discover XID 00000000 from 127.0.0.1:67 to 10.43.18.92:67 via lo

(5)    &DHCP-Opcode = Client-Message

(5)    &DHCP-Hardware-Type = Ethernet

(5)    &DHCP-Hardware-Address-Length = 6

(5)    &DHCP-Hop-Count = 1

(5)    &DHCP-Transaction-Id = 0

(5)    &DHCP-Number-of-Seconds = 0

(5)    &DHCP-Flags = 0

(5)    &DHCP-Client-IP-Address = 127.0.0.1

(5)    &DHCP-Your-IP-Address = 0.0.0.0

(5)    &DHCP-Server-IP-Address = 0.0.0.0

(5)    &DHCP-Gateway-IP-Address = 127.0.0.1

(5)    &DHCP-Client-Hardware-Address = 00:a1:bc:00:00:01

(5)    &DHCP-Requested-IP-Address = 10.1.1.3

(5)    &DHCP-Message-Type = DHCP-Request

(5)    &DHCP-DHCP-Server-Identifier = 10.43.18.92

(5)    &DHCP-Client-Identifier = 0x0100a1bc000001

(5)  Running 'recv DHCP-Discover' from file /usr/local/etc/raddb/sites-enabled/dhcp

(5)  recv DHCP-Discover {

(5)    update reply {

(5)      DHCP-Message-Type = DHCP-Offer

(5)    } # update reply (noop)

(5)    update reply {

(5)      &DHCP-Domain-Name-Server = 127.0.0.1

(5)      &DHCP-Subnet-Mask = 255.255.255.0

(5)      &DHCP-Router-Address = 10.43.18.92

(5)      &DHCP-IP-Address-Lease-Time = 86400

(5)      &DHCP-DHCP-Server-Identifier = 10.43.18.92

(5)    } # update reply (noop)

(5)    mac2ip - Added DHCP-Your-IP-Address: '10.1.1.3' to reply_items

(5)    mac2ip (ok)

(5)    ok (ok)

(5)  } # recv DHCP-Discover (ok)

(5)  Sent DHCP-Offer XID 00000000 from 10.43.18.92:67 to 127.0.0.1:67 via lo

(5)    &DHCP-Message-Type = DHCP-Offer

(5)    &DHCP-Domain-Name-Server = 127.0.0.1

(5)    &DHCP-Subnet-Mask = 255.255.255.0

(5)    &DHCP-Router-Address = 10.43.18.92

(5)    &DHCP-IP-Address-Lease-Time = 86400

(5)    &DHCP-DHCP-Server-Identifier = 10.43.18.92

(5)  done request

(5)  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


-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

test.pcap (3K) Download Attachment
| Threaded
Open this post in threaded view
|

Re: TXID mismatch between DHCP Request-Offer (devel version)

Chinnapaiyan, Nagamani
In reply to this post by Chinnapaiyan, Nagamani
It works after changing the code in my local repo... Thanks... We are storing TXID as it is(without ntohl). But while sending we are doing htonl. Corrected that also.
# git diff
diff --git a/src/modules/proto_dhcpv4/proto_dhcpv4.c b/src/modules/proto_dhcpv4/proto_dhcpv4.c
index 465a3ea..3a80a8f 100644
--- a/src/modules/proto_dhcpv4/proto_dhcpv4.c
+++ b/src/modules/proto_dhcpv4/proto_dhcpv4.c
@@ -416,7 +416,7 @@ static ssize_t mod_encode(void const *instance, REQUEST *request, uint8_t *buffe
        }
        data_len = fr_dhcpv4_encode(buffer, buffer_len,
-                                   request->reply->code, original->xid, request->reply->vps);
+                                   request->reply->code, ntohl(original->xid), request->reply->vps);
        if (data_len < 0) {
                RPEDEBUG("Failed encoding DHCPV4 reply");
                return -1;
diff --git a/src/protocols/dhcpv4/packet.c b/src/protocols/dhcpv4/packet.c
index 5460041..38790f9 100644
--- a/src/protocols/dhcpv4/packet.c
+++ b/src/protocols/dhcpv4/packet.c
@@ -218,6 +218,12 @@ int fr_dhcpv4_packet_decode(RADIUS_PACKET *packet)
                        }
                        p += len;
                }
+//Decode message type from the option.
+VALUE_PAIR *message_type = NULL;
+message_type = fr_pair_find_by_da(head, attr_dhcp_message_type, TAG_ANY);
+if(message_type) {
+packet->code = message_type->vp_uint8;
+}
                /*
                 *      If option Overload is present in the 'options' field, then fields 'file' and/or 'sname'

Regards,
Nagamani Chinnapaiyan

-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
| Threaded
Open this post in threaded view
|

Re: TXID mismatch between DHCP Request-Offer (devel version)

Alan DeKok-2


> On Nov 22, 2018, at 8:54 AM, Chinnapaiyan, Nagamani <[hidden email]> wrote:
>
> It works after changing the code in my local repo... Thanks... We are storing TXID as it is(without ntohl). But while sending we are doing htonl. Corrected that also.

  OK.  I'll add that fix.

> +//Decode message type from the option.
> +VALUE_PAIR *message_type = NULL;
> +message_type = fr_pair_find_by_da(head, attr_dhcp_message_type, TAG_ANY);
> +if(message_type) {
> +packet->code = message_type->vp_uint8;
> +}

  That's not really necessary.  The packet code is already being set by proto_dhcpv4.

  I'll push some more cleanups.

  Alan DeKok.



-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html