Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct
Hi guys i am developing a small project using freeradius, and i have installed freeradius on ubuntu 20.04 version of freeradius is 3.0.20 configured mysql tables, configured sql modules in order to load all data from mysql.. Nas table loading server details ok, radcheck, radgroupcheck, radgroupreply, radipools configured ok.. and client logs in using username and password, and can browse the web normaly, the issue is on radacct table mysql that is not storing data at all, i have rebooted clients device couple of times,to see if radacct would update the log, but nothing happens.. only think i can see is radpostauth storing username, pass xored md5 and login date.. nothing else.. i am pretty sure it must be a configuration mistake from my side surely.. so i will attach below the full output log of the freeradius -x , maybe someone can share some information that i might be missing on the configuration.. any help will be appreciated.. root@PSI-DEV:~# sudo freeradius -X FreeRADIUS Version 3.0.20 Copyright (C) 1999-2019 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 /usr/share/freeradius/dictionary including dictionary file /usr/share/freeradius/dictionary.dhcp including dictionary file /usr/share/freeradius/dictionary.vqp including dictionary file /etc/freeradius/3.0/dictionary including configuration file /etc/freeradius/3.0/radiusd.conf including configuration file /etc/freeradius/3.0/proxy.conf including configuration file /etc/freeradius/3.0/clients.conf including files in directory /etc/freeradius/3.0/mods-enabled/ including configuration file /etc/freeradius/3.0/mods-enabled/linelog including configuration file /etc/freeradius/3.0/mods-enabled/digest including configuration file /etc/freeradius/3.0/mods-enabled/echo including configuration file /etc/freeradius/3.0/mods-enabled/radutmp including configuration file /etc/freeradius/3.0/mods-enabled/passwd including configuration file /etc/freeradius/3.0/mods-enabled/mschap including configuration file /etc/freeradius/3.0/mods-enabled/unix including configuration file /etc/freeradius/3.0/mods-enabled/files including configuration file /etc/freeradius/3.0/mods-enabled/pap including configuration file /etc/freeradius/3.0/mods-enabled/eap including configuration file /etc/freeradius/3.0/mods-enabled/replicate including configuration file /etc/freeradius/3.0/mods-enabled/soh including configuration file /etc/freeradius/3.0/mods-enabled/sql including configuration file /etc/freeradius/3.0/mods-config/sql/main/mysql/queries.conf including configuration file /etc/freeradius/3.0/mods-enabled/logintime including configuration file /etc/freeradius/3.0/mods-enabled/exec including configuration file /etc/freeradius/3.0/mods-enabled/realm including configuration file /etc/freeradius/3.0/mods-enabled/preprocess including configuration file /etc/freeradius/3.0/mods-enabled/cache_eap including configuration file /etc/freeradius/3.0/mods-enabled/sradutmp including configuration file /etc/freeradius/3.0/mods-enabled/expiration including configuration file /etc/freeradius/3.0/mods-enabled/detail including configuration file /etc/freeradius/3.0/mods-enabled/unpack including configuration file /etc/freeradius/3.0/mods-enabled/detail.log including configuration file /etc/freeradius/3.0/mods-enabled/expr including configuration file /etc/freeradius/3.0/mods-enabled/chap including configuration file /etc/freeradius/3.0/mods-enabled/ntlm_auth including configuration file /etc/freeradius/3.0/mods-enabled/always including configuration file /etc/freeradius/3.0/mods-enabled/sqlippool including configuration file /etc/freeradius/3.0/mods-config/sql/ippool/mysql/queries.conf including configuration file /etc/freeradius/3.0/mods-enabled/dynamic_clients including configuration file /etc/freeradius/3.0/mods-enabled/utf8 including configuration file /etc/freeradius/3.0/mods-enabled/attr_filter including files in directory /etc/freeradius/3.0/policy.d/ including configuration file /etc/freeradius/3.0/policy.d/cui including configuration file /etc/freeradius/3.0/policy.d/dhcp including configuration file /etc/freeradius/3.0/policy.d/eap including configuration file /etc/freeradius/3.0/policy.d/filter including configuration file /etc/freeradius/3.0/policy.d/abfab-tr including configuration file /etc/freeradius/3.0/policy.d/debug including configuration file /etc/freeradius/3.0/policy.d/canonicalization including configuration file /etc/freeradius/3.0/policy.d/accounting including configuration file /etc/freeradius/3.0/policy.d/control including configuration file /etc/freeradius/3.0/policy.d/moonshot-targeted-ids including configuration file /etc/freeradius/3.0/policy.d/rfc7542 including configuration file /etc/freeradius/3.0/policy.d/operator-name including files in directory /etc/freeradius/3.0/sites-enabled/ including configuration file /etc/freeradius/3.0/sites-enabled/default including configuration file /etc/freeradius/3.0/sites-enabled/inner-tunnel main { security { user = "freerad" group = "freerad" allow_core_dumps = no } name = "freeradius" prefix = "/usr" localstatedir = "/var" logdir = "/var/log/freeradius" run_dir = "/var/run/freeradius" } main { name = "freeradius" prefix = "/usr" localstatedir = "/var" sbindir = "/usr/sbin" logdir = "/var/log/freeradius" run_dir = "/var/run/freeradius" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/freeradius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 16384 pidfile = "/var/run/freeradius/freeradius.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = yes log { stripped_names = no auth = no auth_badpass = no auth_goodpass = no colourise = yes msg_denied = "You are already logged in - access denied" } resources { } security { max_attributes = 200 reject_delay = 1.000000 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 3 default_fallback = no dead_time = 120 wake_all_if_all_dead = no } home_server localhost { ipaddr = 127.0.0.1 port = 1812 type = "auth" secret = <<< secret >>> response_window = 20.000000 response_timeouts = 1 max_outstanding = 65536 zombie_period = 40 status_check = "status-server" ping_interval = 30 check_interval = 30 check_timeout = 4 num_answers_to_alive = 3 revive_interval = 120 limit { max_connections = 16 max_requests = 0 lifetime = 0 idle_timeout = 0 } coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } } home_server_pool my_auth_failover { type = fail-over home_server = localhost } realm example.com { auth_pool = my_auth_failover } realm LOCAL { } radiusd: #### Loading Clients #### Debugger not attached systemd watchdog is disabled # Creating Auth-Type = mschap # Creating Auth-Type = eap # Creating Auth-Type = PAP # Creating Auth-Type = CHAP # Creating Auth-Type = MS-CHAP radiusd: #### Instantiating modules #### modules { # Loaded module rlm_linelog # Loading module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog linelog { filename = "/var/log/freeradius/linelog" escape_filenames = no syslog_severity = "info" permissions = 384 format = "This is a log message for %{User-Name}" reference = "messages.%{%{reply:Packet-Type}:-default}" } # Loading module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog linelog log_accounting { filename = "/var/log/freeradius/linelog-accounting" escape_filenames = no syslog_severity = "info" permissions = 384 format = "" reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" } # Loaded module rlm_digest # Loading module "digest" from file /etc/freeradius/3.0/mods-enabled/digest # Loaded module rlm_exec # Loading module "echo" from file /etc/freeradius/3.0/mods-enabled/echo exec echo { wait = yes program = "/bin/echo %{User-Name}" input_pairs = "request" output_pairs = "reply" shell_escape = yes } # Loaded module rlm_radutmp # Loading module "radutmp" from file /etc/freeradius/3.0/mods-enabled/radutmp radutmp { filename = "/var/log/freeradius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 384 caller_id = yes } # Loaded module rlm_passwd # Loading module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/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 } # Loaded module rlm_mschap # Loading module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = yes passchange { } allow_retry = yes winbind_retry_with_normalised_username = no } # Loaded module rlm_unix # Loading module "unix" from file /etc/freeradius/3.0/mods-enabled/unix unix { radwtmp = "/var/log/freeradius/radwtmp" } Creating attribute Unix-Group # Loaded module rlm_files # Loading module "files" from file /etc/freeradius/3.0/mods-enabled/files files { filename = "/etc/freeradius/3.0/mods-config/files/authorize" acctusersfile = "/etc/freeradius/3.0/mods-config/files/accounting" preproxy_usersfile = "/etc/freeradius/3.0/mods-config/files/pre-proxy" } # Loaded module rlm_pap # Loading module "pap" from file /etc/freeradius/3.0/mods-enabled/pap pap { normalise = yes } # Loaded module rlm_eap # Loading module "eap" from file /etc/freeradius/3.0/mods-enabled/eap eap { default_eap_type = "md5" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 16384 } # Loaded module rlm_replicate # Loading module "replicate" from file /etc/freeradius/3.0/mods-enabled/replicate # Loaded module rlm_soh # Loading module "soh" from file /etc/freeradius/3.0/mods-enabled/soh soh { dhcp = yes } # Loaded module rlm_sql # Loading module "sql" from file /etc/freeradius/3.0/mods-enabled/sql sql { driver = "rlm_sql_mysql" server = "localhost" port = 3306 login = "radius" password = <<< secret >>> radius_db = "radius" read_groups = yes read_profiles = yes read_clients = yes delete_stale_sessions = yes sql_user_name = "%{User-Name}" logfile = "/var/log/freeradius/radacct/sql.log" default_user_profile = "" client_query = "SELECT id, nasname, shortname, type, secret, server FROM nas" authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id" authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id" authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id" authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id" group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" simul_count_query = "SELECT COUNT(*) FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" auto_escape = no accounting { reference = "%{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.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}')" } interim-update { query = "UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctinterval = %{integer:Event-Timestamp} - UNIX_TIMESTAMP(@acctupdatetime_old), acctstoptime = NULL, 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}'" } 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}'" } } } post-auth { reference = ".query" logfile = "/var/log/freeradius/post-auth.sql" query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" } } rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Creating attribute SQL-Group # Loaded module rlm_logintime # Loading module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime logintime { minimum_timeout = 60 } # Loading module "exec" from file /etc/freeradius/3.0/mods-enabled/exec exec { wait = no input_pairs = "request" shell_escape = yes timeout = 10 } # Loaded module rlm_realm # Loading module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm realm IPASS { format = "prefix" delimiter = "/" ignore_default = no ignore_null = no } # Loading module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } # Loading module "bangpath" from file /etc/freeradius/3.0/mods-enabled/realm realm bangpath { format = "prefix" delimiter = "!" ignore_default = no ignore_null = no } # Loading module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm realm realmpercent { format = "suffix" delimiter = "%" ignore_default = no ignore_null = no } # Loading module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm realm ntdomain { format = "prefix" delimiter = "\\" ignore_default = no ignore_null = no } # Loaded module rlm_preprocess # Loading module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess preprocess { huntgroups = "/etc/freeradius/3.0/mods-config/preprocess/huntgroups" hints = "/etc/freeradius/3.0/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 } # Loaded module rlm_cache # Loading module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap cache cache_eap { driver = "rlm_cache_rbtree" key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}" ttl = 15 max_entries = 0 epoch = 0 add_stats = no } # Loading module "sradutmp" from file /etc/freeradius/3.0/mods-enabled/sradutmp radutmp sradutmp { filename = "/var/log/freeradius/sradutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 420 caller_id = no } # Loaded module rlm_expiration # Loading module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration # Loaded module rlm_detail # Loading module "detail" from file /etc/freeradius/3.0/mods-enabled/detail detail { filename = "/var/log/freeradius/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 } # Loaded module rlm_unpack # Loading module "unpack" from file /etc/freeradius/3.0/mods-enabled/unpack # Loading module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log detail auth_log { filename = "/var/log/freeradius/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 } # Loading module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log detail reply_log { filename = "/var/log/freeradius/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 } # Loading module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log detail pre_proxy_log { filename = "/var/log/freeradius/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 } # Loading module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log detail post_proxy_log { filename = "/var/log/freeradius/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 } # Loaded module rlm_expr # Loading module "expr" from file /etc/freeradius/3.0/mods-enabled/expr expr { safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôoùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔOÙÛÜY" } # Loaded module rlm_chap # Loading module "chap" from file /etc/freeradius/3.0/mods-enabled/chap # Loading module "ntlm_auth" from file /etc/freeradius/3.0/mods-enabled/ntlm_auth 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 } # Loaded module rlm_always # Loading module "reject" from file /etc/freeradius/3.0/mods-enabled/always always reject { rcode = "reject" simulcount = 0 mpp = no } # Loading module "fail" from file /etc/freeradius/3.0/mods-enabled/always always fail { rcode = "fail" simulcount = 0 mpp = no } # Loading module "ok" from file /etc/freeradius/3.0/mods-enabled/always always ok { rcode = "ok" simulcount = 0 mpp = no } # Loading module "handled" from file /etc/freeradius/3.0/mods-enabled/always always handled { rcode = "handled" simulcount = 0 mpp = no } # Loading module "invalid" from file /etc/freeradius/3.0/mods-enabled/always always invalid { rcode = "invalid" simulcount = 0 mpp = no } # Loading module "userlock" from file /etc/freeradius/3.0/mods-enabled/always always userlock { rcode = "userlock" simulcount = 0 mpp = no } # Loading module "notfound" from file /etc/freeradius/3.0/mods-enabled/always always notfound { rcode = "notfound" simulcount = 0 mpp = no } # Loading module "noop" from file /etc/freeradius/3.0/mods-enabled/always always noop { rcode = "noop" simulcount = 0 mpp = no } # Loading module "updated" from file /etc/freeradius/3.0/mods-enabled/always always updated { rcode = "updated" simulcount = 0 mpp = no } # Loaded module rlm_sqlippool # Loading module "sqlippool" from file /etc/freeradius/3.0/mods-enabled/sqlippool sqlippool { sql_module_instance = "sql" lease_duration = 1600 pool_name = "Pool-Name" default_pool = "main_pool" allow_duplicates = no attribute_name = "Framed-IP-Address" allocate_begin = "START TRANSACTION" allocate_clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '%{Calling-Station-Id}'" allocate_clear_timeout = 1 allocate_find = "SELECT framedipaddress FROM radippool WHERE pool_name = '%{control:Pool-Name}' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE" allocate_update = "UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}', callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '%I'" allocate_commit = "COMMIT" pool_check = "SELECT id FROM radippool WHERE pool_name='%{control:Pool-Name}' LIMIT 1" start_begin = "START TRANSACTION" start_update = "UPDATE radippool SET expiry_time = NOW() + INTERVAL 1600 SECOND WHERE nasipaddress = '%{NAS-IP-Address}' AND pool_key = '%{Calling-Station-Id}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" start_commit = "COMMIT" alive_begin = "START TRANSACTION" alive_update = "UPDATE radippool SET expiry_time = NOW() + INTERVAL 1600 SECOND WHERE nasipaddress = '%{%{Nas-IP-Address}:-%{Nas-IPv6-Address}}' AND pool_key = '%{Calling-Station-Id}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" alive_commit = "COMMIT" stop_begin = "START TRANSACTION" stop_clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '%{%{Nas-IP-Address}:-%{Nas-IPv6-Address}}' AND pool_key = '%{Calling-Station-Id}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" stop_commit = "COMMIT" on_begin = "START TRANSACTION" on_clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '%{%{Nas-IP-Address}:-%{Nas-IPv6-Address}}'" on_commit = "COMMIT" off_begin = "START TRANSACTION" off_clear = "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '%{%{Nas-IP-Address}:-%{Nas-IPv6-Address}}'" off_commit = "COMMIT" messages { exists = "Existing IP: %{reply:Framed-IP-Address} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})" success = "Allocated IP: %{reply:Framed-IP-Address} from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})" clear = "Released IP Framed-IP-Address (did %{Called-Station-Id} cli %{Calling-Station-Id} user %{User-Name})" failed = "IP Allocation FAILED from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})" nopool = "No Pool-Name defined (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})" } } # Loaded module rlm_dynamic_clients # Loading module "dynamic_clients" from file /etc/freeradius/3.0/mods-enabled/dynamic_clients # Loaded module rlm_utf8 # Loading module "utf8" from file /etc/freeradius/3.0/mods-enabled/utf8 # Loaded module rlm_attr_filter # Loading module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter attr_filter attr_filter.post-proxy { filename = "/etc/freeradius/3.0/mods-config/attr_filter/post-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter attr_filter attr_filter.pre-proxy { filename = "/etc/freeradius/3.0/mods-config/attr_filter/pre-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter attr_filter attr_filter.access_reject { filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_reject" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter attr_filter attr_filter.access_challenge { filename = "/etc/freeradius/3.0/mods-config/attr_filter/access_challenge" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter attr_filter attr_filter.accounting_response { filename = "/etc/freeradius/3.0/mods-config/attr_filter/accounting_response" key = "%{User-Name}" relaxed = no } # Instantiating module "linelog" from file /etc/freeradius/3.0/mods-enabled/linelog # Instantiating module "log_accounting" from file /etc/freeradius/3.0/mods-enabled/linelog # Instantiating module "etc_passwd" from file /etc/freeradius/3.0/mods-enabled/passwd rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no # Instantiating module "mschap" from file /etc/freeradius/3.0/mods-enabled/mschap rlm_mschap (mschap): using internal authentication # Instantiating module "files" from file /etc/freeradius/3.0/mods-enabled/files reading pairlist file /etc/freeradius/3.0/mods-config/files/authorize reading pairlist file /etc/freeradius/3.0/mods-config/files/accounting reading pairlist file /etc/freeradius/3.0/mods-config/files/pre-proxy # Instantiating module "pap" from file /etc/freeradius/3.0/mods-enabled/pap # Instantiating module "eap" from file /etc/freeradius/3.0/mods-enabled/eap # Linked to sub-module rlm_eap_md5 # Linked to sub-module rlm_eap_leap # Linked to sub-module rlm_eap_gtc gtc { challenge = "Password: " auth_type = "PAP" } # Linked to sub-module rlm_eap_tls tls { tls = "tls-common" } tls-config tls-common { verify_depth = 0 ca_path = "/etc/freeradius/3.0/certs" pem_file_type = yes private_key_file = "/etc/ssl/private/ssl-cert-snakeoil.key" certificate_file = "/etc/ssl/certs/ssl-cert-snakeoil.pem" ca_file = "/etc/ssl/certs/ca-certificates.crt" private_key_password = <<< secret >>> dh_file = "/etc/freeradius/3.0/certs/dh" fragment_size = 1024 include_length = yes auto_chain = yes check_crl = no check_all_crl = no cipher_list = "DEFAULT" cipher_server_preference = no ecdh_curve = "prime256v1" tls_max_version = "" tls_min_version = "1.0" cache { enable = no lifetime = 24 max_entries = 255 } verify { skip_if_ocsp_ok = no } ocsp { enable = no override_cert_url = yes url = "http://127.0.0.1/ocsp/" use_nonce = yes timeout = 0 softfail = no } } The configuration allows TLS 1.0 and/or TLS 1.1. We STRONGLY recommned using only TLS 1.2 for security Please set: min_tls_version = "1.2" # Linked to sub-module rlm_eap_ttls ttls { tls = "tls-common" default_eap_type = "md5" copy_request_to_tunnel = no use_tunneled_reply = no virtual_server = "inner-tunnel" include_length = yes require_client_cert = no } tls: Using cached TLS configuration from previous invocation # Linked to sub-module rlm_eap_peap peap { tls = "tls-common" default_eap_type = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" soh = no require_client_cert = no } tls: Using cached TLS configuration from previous invocation # Linked to sub-module rlm_eap_mschapv2 mschapv2 { with_ntdomain_hack = no send_error = no } # Instantiating module "sql" from file /etc/freeradius/3.0/mods-enabled/sql rlm_sql_mysql: libmysql version: 8.0.30 mysql { tls { tls_required = no check_cert = no check_cert_cn = no } warnings = "auto" } rlm_sql (sql): Attempting to connect to database "radius" rlm_sql (sql): Initialising connection pool pool { start = 5 min = 3 max = 32 spare = 10 uses = 0 lifetime = 0 cleanup_interval = 30 idle_timeout = 60 retry_delay = 30 spread = no } rlm_sql (sql): Opening additional connection (0), 1 of 32 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Opening additional connection (1), 1 of 31 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Opening additional connection (2), 1 of 30 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Opening additional connection (3), 1 of 29 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Opening additional connection (4), 1 of 28 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Processing generate_sql_clients rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas rlm_sql (sql): Reserved connection (0) rlm_sql (sql): Executing select query: SELECT id, nasname, shortname, type, secret, server FROM nas rlm_sql (sql): Adding client 10.5.5.17 (BRAS RB4011 TEST) to global clients list rlm_sql (10.5.5.17): Client "BRAS RB4011 TEST" (sql) added rlm_sql (sql): Released connection (0) Need 5 more connections to reach 10 spares rlm_sql (sql): Opening additional connection (5), 1 of 27 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 # Instantiating module "logintime" from file /etc/freeradius/3.0/mods-enabled/logintime # Instantiating module "IPASS" from file /etc/freeradius/3.0/mods-enabled/realm # Instantiating module "suffix" from file /etc/freeradius/3.0/mods-enabled/realm # Instantiating module "bangpath" from file /etc/freeradius/3.0/mods-enabled/realm # Instantiating module "realmpercent" from file /etc/freeradius/3.0/mods-enabled/realm # Instantiating module "ntdomain" from file /etc/freeradius/3.0/mods-enabled/realm # Instantiating module "preprocess" from file /etc/freeradius/3.0/mods-enabled/preprocess reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/huntgroups reading pairlist file /etc/freeradius/3.0/mods-config/preprocess/hints # Instantiating module "cache_eap" from file /etc/freeradius/3.0/mods-enabled/cache_eap rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked # Instantiating module "expiration" from file /etc/freeradius/3.0/mods-enabled/expiration # Instantiating module "detail" from file /etc/freeradius/3.0/mods-enabled/detail # Instantiating module "auth_log" from file /etc/freeradius/3.0/mods-enabled/detail.log rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output # Instantiating module "reply_log" from file /etc/freeradius/3.0/mods-enabled/detail.log # Instantiating module "pre_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log # Instantiating module "post_proxy_log" from file /etc/freeradius/3.0/mods-enabled/detail.log # Instantiating module "reject" from file /etc/freeradius/3.0/mods-enabled/always # Instantiating module "fail" from file /etc/freeradius/3.0/mods-enabled/always # Instantiating module "ok" from file /etc/freeradius/3.0/mods-enabled/always # Instantiating module "handled" from file /etc/freeradius/3.0/mods-enabled/always # Instantiating module "invalid" from file /etc/freeradius/3.0/mods-enabled/always # Instantiating module "userlock" from file /etc/freeradius/3.0/mods-enabled/always # Instantiating module "notfound" from file /etc/freeradius/3.0/mods-enabled/always # Instantiating module "noop" from file /etc/freeradius/3.0/mods-enabled/always # Instantiating module "updated" from file /etc/freeradius/3.0/mods-enabled/always # Instantiating module "sqlippool" from file /etc/freeradius/3.0/mods-enabled/sqlippool Ignoring "allocate_clear_timeout = 1", forcing to "allocate_clear_timeout = 1" # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/post-proxy # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/3.0/mods-enabled/attr_filter reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/pre-proxy # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/3.0/mods-enabled/attr_filter reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_reject # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/3.0/mods-enabled/attr_filter reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/access_challenge # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/3.0/mods-enabled/attr_filter reading pairlist file /etc/freeradius/3.0/mods-config/attr_filter/accounting_response } # modules radiusd: #### Loading Virtual Servers #### server { # from file /etc/freeradius/3.0/radiusd.conf } # server server default { # from file /etc/freeradius/3.0/sites-enabled/default # Loading authenticate {...} # Loading authorize {...} # Loading preacct {...} # Loading accounting {...} # Loading session {...} # Loading post-proxy {...} # Loading post-auth {...} } # server default server inner-tunnel { # from file /etc/freeradius/3.0/sites-enabled/inner-tunnel # Loading authenticate {...} # Loading authorize {...} # Loading session {...} # Loading post-proxy {...} # Loading post-auth {...} } # server inner-tunnel radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = * port = 1812 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "acct" ipaddr = * port = 1813 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "auth" ipv6addr = :: port = 1812 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "acct" ipv6addr = :: port = 1813 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } Listening on auth address * port 1812 bound to server default Listening on acct address * port 1813 bound to server default Listening on auth address :: port 1812 bound to server default Listening on acct address :: port 1813 bound to server default Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Listening on proxy address * port 36859 Listening on proxy address :: port 42334 Ready to process requests (0) Received Access-Request Id 122 from 10.5.5.17:35276 to 10.7.7.20:1812 length 196 (0) Service-Type = Framed-User (0) Framed-Protocol = PPP (0) NAS-Port = 15743036 (0) NAS-Port-Type = Ethernet (0) User-Name = "isptest200" (0) Calling-Station-Id = "80:8B:EB:B2:73:DB" (0) Called-Station-Id = "PPPOE-FIBER" (0) NAS-Port-Id = "VLAN1250 - FIBER" (0) Acct-Session-Id = "81e03832" (0) CHAP-Challenge = 0x5121406b2f5e153087cbb4adecd88780 (0) CHAP-Password = 0x019f2a968bf91f2df371a75863f391d707 (0) NAS-Identifier = "ROUTER PPPoE TEST" (0) NAS-IP-Address = 10.5.5.17 (0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (0) authorize { (0) policy filter_username { (0) if (&User-Name) { (0) if (&User-Name) -> TRUE (0) if (&User-Name) { (0) if (&User-Name =~ / /) { (0) if (&User-Name =~ / /) -> FALSE (0) if (&User-Name =~ /@[^@]*@/ ) { (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (0) if (&User-Name =~ /\.\./ ) { (0) if (&User-Name =~ /\.\./ ) -> FALSE (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE (0) if (&User-Name =~ /\.$/) { (0) if (&User-Name =~ /\.$/) -> FALSE (0) if (&User-Name =~ /@\./) { (0) if (&User-Name =~ /@\./) -> FALSE (0) } # if (&User-Name) = notfound (0) } # policy filter_username = notfound (0) [preprocess] = ok (0) chap: &control:Auth-Type := CHAP (0) [chap] = ok (0) [mschap] = noop (0) eap: No EAP-Message, not doing EAP (0) [eap] = noop (0) sql: EXPAND %{User-Name} (0) sql: --> isptest200 (0) sql: SQL-User-Name set to 'isptest200' rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 77 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 77 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 77 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 77 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 77 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 77 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare" rlm_sql (sql): Opening additional connection (6), 1 of 32 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Reserved connection (6) (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'isptest200' ORDER BY id (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'isptest200' ORDER BY id (0) sql: User found in radcheck table (0) sql: Conditional check items matched, merging assignment check items (0) sql: Cleartext-Password := "123123" (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (0) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'isptest200' ORDER BY id (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'isptest200' ORDER BY id rlm_sql (sql): 1 of 1 connections in use. You may need to increase "spare" rlm_sql (sql): Opening additional connection (7), 1 of 31 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Reserved connection (7) rlm_sql (sql): Released connection (7) Need 1 more connections to reach min connections (3) rlm_sql (sql): Opening additional connection (8), 1 of 30 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority (0) sql: --> SELECT groupname FROM radusergroup WHERE username = 'isptest200' ORDER BY priority (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'isptest200' ORDER BY priority (0) sql: User found in the group table (0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id (0) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fiber_test_500' ORDER BY id (0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fiber_test_500' ORDER BY id (0) sql: Group "fiber_test_500": Conditional check items matched (0) sql: Group "fiber_test_500": Merging assignment check items (0) sql: Framed-Protocol := PPP (0) sql: Pool-Name := "pool_freeradiustest" (0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id (0) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fiber_test_500' ORDER BY id (0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fiber_test_500' ORDER BY id (0) sql: Group "fiber_test_500": Merging reply items (0) sql: Mikrotik-Rate-Limit := "500M/500M" (0) sql: Acct-Interim-Interval := 300 (0) sql: MS-Primary-DNS-Server := 192.168.16.10 (0) sql: MS-Secondary-DNS-Server := 192.168.16.11 rlm_sql (sql): Released connection (6) (0) [sql] = ok (0) [expiration] = noop (0) [logintime] = noop (0) pap: WARNING: Auth-Type already set. Not setting to PAP (0) [pap] = noop (0) } # authorize = ok (0) Found Auth-Type = CHAP (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default (0) Auth-Type CHAP { (0) chap: Comparing with "known good" Cleartext-Password (0) chap: CHAP user "isptest200" authenticated successfully (0) [chap] = ok (0) } # Auth-Type CHAP = ok (0) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/default (0) post-auth { (0) update { (0) No attributes updated for RHS &session-state: (0) } # update = noop (0) sql: EXPAND .query (0) sql: --> .query (0) sql: Using query template 'query' rlm_sql (sql): Reserved connection (6) (0) sql: EXPAND %{User-Name} (0) sql: --> isptest200 (0) sql: SQL-User-Name set to 'isptest200' (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'isptest200', '0x019f2a968bf91f2df371a75863f391d707', 'Access-Accept', '2022-09-01 21:34:59') (0) sql: EXPAND /var/log/freeradius/post-auth.sql (0) sql: --> /var/log/freeradius/post-auth.sql (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'isptest200', '0x019f2a968bf91f2df371a75863f391d707', 'Access-Accept', '2022-09-01 21:34:59') (0) sql: SQL query returned: success (0) sql: 1 record(s) updated rlm_sql (sql): Released connection (6) (0) [sql] = ok rlm_sql (sql): Reserved connection (7) (0) sqlippool: EXPAND %{User-Name} (0) sqlippool: --> isptest200 (0) sqlippool: SQL-User-Name set to 'isptest200' (0) sqlippool: EXPAND START TRANSACTION (0) sqlippool: --> START TRANSACTION (0) sqlippool: Executing query: START TRANSACTION (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '%{Calling-Station-Id}' (0) sqlippool: --> UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8B:EB:B2:73:DB' (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8B:EB:B2:73:DB' rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0 (0) sqlippool: EXPAND COMMIT (0) sqlippool: --> COMMIT (0) sqlippool: Executing query: COMMIT (0) sqlippool: EXPAND START TRANSACTION (0) sqlippool: --> START TRANSACTION (0) sqlippool: Executing query: START TRANSACTION (0) sqlippool: EXPAND SELECT framedipaddress FROM radippool WHERE pool_name = '%{control:Pool-Name}' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE (0) sqlippool: --> SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_freeradiustest' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE (0) sqlippool: Executing select query: SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_freeradiustest' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE (0) sqlippool: Allocated IP 100.64.20.144 (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}', callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144' (0) sqlippool: --> UPDATE radippool SET nasipaddress = '10.5.5.17', pool_key = '80:8B:EB:B2:73:DB', callingstationid = '80:8B:EB:B2:73:DB', username = 'isptest200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144' (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '10.5.5.17', pool_key = '80:8B:EB:B2:73:DB', callingstationid = '80:8B:EB:B2:73:DB', username = 'isptest200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144' rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0 (0) sqlippool: EXPAND COMMIT (0) sqlippool: --> COMMIT (0) sqlippool: Executing query: COMMIT rlm_sql (sql): Released connection (7) (0) sqlippool: EXPAND Allocated IP: %{reply:Framed-IP-Address} from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name}) (0) sqlippool: --> Allocated IP: 100.64.20.144 from pool_freeradiustest (did PPPOE-FIBRA cli 80:8B:EB:B2:73:DB port 15743036 user isptest200) (0) [sqlippool] = ok (0) policy remove_reply_message_if_eap { (0) if (&reply:EAP-Message && &reply:Reply-Message) { (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (0) else { (0) [noop] = noop (0) } # else = noop (0) } # policy remove_reply_message_if_eap = noop (0) } # post-auth = ok (0) Sent Access-Accept Id 122 from 10.7.7.20:1812 to 10.5.5.17:35276 length 0 (0) Mikrotik-Rate-Limit = "500M/500M" (0) Acct-Interim-Interval = 300 (0) MS-Primary-DNS-Server = 192.168.16.10 (0) MS-Secondary-DNS-Server = 192.168.16.11 (0) Framed-IP-Address = 100.64.20.144 (0) Finished request Waking up in 4.9 seconds. (0) Cleaning up request packet ID 122 with timestamp +77 Ready to process requests
On 02/09/2022 02:59, Pedro Daniel Costa wrote:
radcheck, radgroupcheck, radgroupreply, radipools configured ok.. and client logs in using username and password, and can browse the web normaly, the issue is on radacct table mysql that is not storing data at all, i have rebooted clients device couple of times,to see if radacct would update the log, but nothing happens.. only think i can see is radpostauth storing username, pass xored md5 and login date.. nothing else..
Configure the NAS to send accounting packets. If FreeRADIUS doesn't receive any information it can't log anything. -- Matthew
Hi Matthew thanks for your input, my NAS data is stored inside MYSQL nas table.. i just set sql to fetch data from it.. could you please guide me on which file i need to edit? because on my sites/enabled, default file i have accounting selected with sql inside the accounting . but for some reason its not updating the data inside the radact table.. inside accounting i have sql,detail,sqlipool enabled.. sqlipool seems to log just the login information and stores it inside the the radipool table. Enviado do Outlook<http://aka.ms/weboutlook> ________________________________ De: Freeradius-Users <freeradius-users-bounces+portalnet2=outlook.com.br@lists.freeradius.org> em nome de Matthew Newton <mcn@freeradius.org> Enviado: quinta-feira, 1 de setembro de 2022 23:21 Para: freeradius-users@lists.freeradius.org <freeradius-users@lists.freeradius.org> Assunto: Re: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct On 02/09/2022 02:59, Pedro Daniel Costa wrote:
radcheck, radgroupcheck, radgroupreply, radipools configured ok.. and client logs in using username and password, and can browse the web normaly, the issue is on radacct table mysql that is not storing data at all, i have rebooted clients device couple of times,to see if radacct would update the log, but nothing happens.. only think i can see is radpostauth storing username, pass xored md5 and login date.. nothing else..
Configure the NAS to send accounting packets. If FreeRADIUS doesn't receive any information it can't log anything. -- Matthew - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
strange part is that default file is configured with accounting enabled.. inner-tunnel also on the init log can see accouting being loaded.. radiusd: #### Loading Virtual Servers #### server { # from file /etc/freeradius/3.0/radiusd.conf } # server server default { # from file /etc/freeradius/3.0/sites-enabled/default # Loading authenticate {...} # Loading authorize {...} # Loading accounting {...} # Loading session {...} # Loading post-auth {...} } # server default server inner-tunnel { # from file /etc/freeradius/3.0/sites-enabled/inner-tunnel # Loading authenticate {...} # Loading authorize {...} # Loading preacct {...} # Loading accounting {...} # Loading session {...} # Loading post-auth {...} } # server inner-tunnel radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = * port = 1812 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "acct" ipaddr = * port = 1813 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "auth" ipv6addr = :: port = 1812 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "acct" ipv6addr = :: port = 1813 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } Listening on auth address * port 1812 bound to server default Listening on acct address * port 1813 bound to server default Listening on auth address :: port 1812 bound to server default Listening on acct address :: port 1813 bound to server default Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Ready to process requests Enviado do Outlook<http://aka.ms/weboutlook> ________________________________ De: Freeradius-Users <freeradius-users-bounces+portalnet2=outlook.com.br@lists.freeradius.org> em nome de Pedro Daniel Costa <portalnet2@outlook.com.br> Enviado: sábado, 3 de setembro de 2022 10:33 Para: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Assunto: RE: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct Hi Matthew thanks for your input, my NAS data is stored inside MYSQL nas table.. i just set sql to fetch data from it.. could you please guide me on which file i need to edit? because on my sites/enabled, default file i have accounting selected with sql inside the accounting . but for some reason its not updating the data inside the radact table.. inside accounting i have sql,detail,sqlipool enabled.. sqlipool seems to log just the login information and stores it inside the the radipool table. Enviado do Outlook<http://aka.ms/weboutlook> ________________________________ De: Freeradius-Users <freeradius-users-bounces+portalnet2=outlook.com.br@lists.freeradius.org> em nome de Matthew Newton <mcn@freeradius.org> Enviado: quinta-feira, 1 de setembro de 2022 23:21 Para: freeradius-users@lists.freeradius.org <freeradius-users@lists.freeradius.org> Assunto: Re: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct On 02/09/2022 02:59, Pedro Daniel Costa wrote:
radcheck, radgroupcheck, radgroupreply, radipools configured ok.. and client logs in using username and password, and can browse the web normaly, the issue is on radacct table mysql that is not storing data at all, i have rebooted clients device couple of times,to see if radacct would update the log, but nothing happens.. only think i can see is radpostauth storing username, pass xored md5 and login date.. nothing else..
Configure the NAS to send accounting packets. If FreeRADIUS doesn't receive any information it can't log anything. -- Matthew - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
On 03/09/2022 14:33, Pedro Daniel Costa wrote:
thanks for your input, my NAS data is stored inside MYSQL nas table.. i just set sql to fetch data from it.. could you please guide me on which file i need to edit?
As I said, you need to configure your NAS (the device with IP 10.5.5.17) to send accounting packets. No amount of configuring FreeRADIUS will fix this. FreeRADIUS can't process an accounting packet that it never received. -- Matthew
Hi Matthew.. indeed it makes sense.. Thats why i have setup inside the mysql table nas on the collumns nasname the ip 1.5.5.17 as shown on the Picture below.. [cid:image001.png@01D8BF85.0697B1F0] Unless i am missing something else or i didn´t get your comment “you need to configure NAS withe device IP” were you refering to the mysql NAS table collumn nasname ? btw .. accounting is done on port 1812 ? or 1813? Enviado do Email<https://go.microsoft.com/fwlink/?LinkId=550986> para Windows De: Matthew Newton<mailto:mcn@freeradius.org> Enviado:sábado, 3 de setembro de 2022 11:01 Para: freeradius-users@lists.freeradius.org<mailto:freeradius-users@lists.freeradius.org> Assunto: Re: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct On 03/09/2022 14:33, Pedro Daniel Costa wrote:
thanks for your input, my NAS data is stored inside MYSQL nas table.. i just set sql to fetch data from it.. could you please guide me on which file i need to edit?
As I said, you need to configure your NAS (the device with IP 10.5.5.17) to send accounting packets. No amount of configuring FreeRADIUS will fix this. FreeRADIUS can't process an accounting packet that it never received. -- Matthew - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
As I said, you need to configure your NAS (the device with IP 10.5.5.17) to send accounting packets. No amount of configuring FreeRADIUS will fix this. Ok i think i understood now what you meant with device with ip 10.5.5.17 , you meant my hardware radius server (my mikrotik test device) Yes i did check this yesterday and its enabled.. on accounting port 1813
If you do a tcpdump on the radius server, are you seeing accounting packets arriving on port 1813 from 10.5.5.17 ?
On Sep 3, 2022, at 10:15 AM, Pedro Daniel Costa <portalnet2@outlook.com.br> wrote:
As I said, you need to configure your NAS (the device with IP 10.5.5.17) to send accounting packets. No amount of configuring FreeRADIUS will fix this.
Ok i think i understood now what you meant with device with ip 10.5.5.17 , you meant my hardware radius server (my mikrotik test device) Yes i did check this yesterday and its enabled.. on accounting port 1813 - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Thats the problem, o freeradius -x no accounting shown on the log all i can see is on init modules and accounting being loaded.. but when device connects.. only radipool gets updated.. As shown on log below once freeradius reveices request from my radius server mikrotik device Ready to process requests (0) Received Access-Request Id 185 from 1.5.5.17:47154 to 10.5.5.200:1812 length 196 (0) Service-Type = Framed-User (0) Framed-Protocol = PPP (0) NAS-Port = 15751547 (0) NAS-Port-Type = Ethernet (0) User-Name = "ispteste200" (0) Calling-Station-Id = "80:8F:E8:F2:73:DB" (0) Called-Station-Id = "PPPOE-FIBRA" (0) NAS-Port-Id = "VLAN1250 - FIBRA PPPOE-PONTAL" (0) Acct-Session-Id = "81e05971" (0) CHAP-Challenge = 0xc602bf8d4fbf361e9d3746f5ae6dbe1e (0) CHAP-Password = 0x011b258f5bb0b1aad089ab2593de5d2fab (0) NAS-Identifier = "ROUTER P0NT4L PPP0E 2" (0) NAS-IP-Address = 1.5.5.17 (0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (0) authorize { (0) chap: &control:Auth-Type := CHAP (0) [chap] = ok (0) [mschap] = noop (0) eap: No EAP-Message, not doing EAP (0) [eap] = noop (0) sql: EXPAND %{User-Name} (0) sql: --> ispteste200 (0) sql: SQL-User-Name set to 'ispteste200' rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 206 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 206 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 206 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 206 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 206 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 206 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare" rlm_sql (sql): Opening additional connection (6), 1 of 32 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Reserved connection (6) (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ispteste200' ORDER BY id (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ispteste200' ORDER BY id (0) sql: User found in radcheck table (0) sql: Conditional check items matched, merging assignment check items (0) sql: Cleartext-Password := "123123" (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (0) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ispteste200' ORDER BY id (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ispteste200' ORDER BY id rlm_sql (sql): 1 of 1 connections in use. You may need to increase "spare" rlm_sql (sql): Opening additional connection (7), 1 of 31 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Reserved connection (7) rlm_sql (sql): Released connection (7) Need 1 more connections to reach min connections (3) rlm_sql (sql): Opening additional connection (8), 1 of 30 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority (0) sql: --> SELECT groupname FROM radusergroup WHERE username = 'ispteste200' ORDER BY priority (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'ispteste200' ORDER BY priority (0) sql: User found in the group table (0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id (0) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fibra_50' ORDER BY id (0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fibra_50' ORDER BY id (0) sql: Group "fibra_50": Conditional check items matched (0) sql: Group "fibra_50": Merging assignment check items (0) sql: Framed-Protocol := PPP (0) sql: Pool-Name := "pool_pontal" (0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id (0) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fibra_50' ORDER BY id (0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fibra_50' ORDER BY id (0) sql: Group "fibra_50": Merging reply items (0) sql: Mikrotik-Rate-Limit := "500M/500M" (0) sql: Acct-Interim-Interval := 300 (0) sql: MS-Primary-DNS-Server := 192.168.10.10 (0) sql: MS-Secondary-DNS-Server := 192.168.10.11 rlm_sql (sql): Released connection (6) (0) [sql] = ok (0) [expiration] = noop (0) [logintime] = noop (0) } # authorize = ok (0) Found Auth-Type = CHAP (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default (0) Auth-Type CHAP { (0) chap: Comparing with "known good" Cleartext-Password (0) chap: CHAP user "ispteste200" authenticated successfully (0) [chap] = ok (0) } # Auth-Type CHAP = ok (0) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/default (0) post-auth { (0) update { (0) No attributes updated for RHS &session-state: (0) } # update = noop (0) sql: EXPAND .query (0) sql: --> .query (0) sql: Using query template 'query' rlm_sql (sql): Reserved connection (6) (0) sql: EXPAND %{User-Name} (0) sql: --> ispteste200 (0) sql: SQL-User-Name set to 'ispteste200' (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ispteste200', '0x011b258f5bb0b1aad089ab2593de5d2fab', 'Access-Accept', '2022-09-03 10:54:19') (0) sql: EXPAND /var/log/freeradius/post-auth.sql (0) sql: --> /var/log/freeradius/post-auth.sql (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ispteste200', '0x011b258f5bb0b1aad089ab2593de5d2fab', 'Access-Accept', '2022-09-03 10:54:19') (0) sql: SQL query returned: success (0) sql: 1 record(s) updated rlm_sql (sql): Released connection (6) (0) [sql] = ok rlm_sql (sql): Reserved connection (7) (0) sqlippool: EXPAND %{User-Name} (0) sqlippool: --> ispteste200 (0) sqlippool: SQL-User-Name set to 'ispteste200' (0) sqlippool: EXPAND START TRANSACTION (0) sqlippool: --> START TRANSACTION (0) sqlippool: Executing query: START TRANSACTION (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '%{Calling-Station-Id}' (0) sqlippool: --> UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8F:E8:F2:73:DB' (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8F:E8:F2:73:DB' rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0 (0) sqlippool: EXPAND COMMIT (0) sqlippool: --> COMMIT (0) sqlippool: Executing query: COMMIT (0) sqlippool: EXPAND START TRANSACTION (0) sqlippool: --> START TRANSACTION (0) sqlippool: Executing query: START TRANSACTION (0) sqlippool: EXPAND SELECT framedipaddress FROM radippool WHERE pool_name = '%{control:Pool-Name}' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE (0) sqlippool: --> SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_pontal' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE (0) sqlippool: Executing select query: SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_pontal' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE (0) sqlippool: Allocated IP 100.64.20.144 (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}', callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144' (0) sqlippool: --> UPDATE radippool SET nasipaddress = '1.5.5.17', pool_key = '80:8F:E8:F2:73:DB', callingstationid = '80:8F:E8:F2:73:DB', username = 'ispteste200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144' (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '1.5.5.17', pool_key = '80:8F:E8:F2:73:DB', callingstationid = '80:8F:E8:F2:73:DB', username = 'ispteste200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144' rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0 (0) sqlippool: EXPAND COMMIT (0) sqlippool: --> COMMIT (0) sqlippool: Executing query: COMMIT rlm_sql (sql): Released connection (7) (0) sqlippool: EXPAND Allocated IP: %{reply:Framed-IP-Address} from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name}) (0) sqlippool: --> Allocated IP: 100.64.20.144 from pool_pontal (did PPPOE-FIBRA cli 80:8F:E8:F2:73:DB port 15751547 user ispteste200) (0) [sqlippool] = ok (0) policy remove_reply_message_if_eap { (0) if (&reply:EAP-Message && &reply:Reply-Message) { (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (0) else { (0) [noop] = noop (0) } # else = noop (0) } # policy remove_reply_message_if_eap = noop (0) } # post-auth = ok (0) Sent Access-Accept Id 185 from 10.5.5.200:1812 to 1.5.5.17:47154 length 0 (0) Mikrotik-Rate-Limit = "500M/500M" (0) Acct-Interim-Interval = 300 (0) MS-Primary-DNS-Server = 192.168.10.10 (0) MS-Secondary-DNS-Server = 192.168.10.11 (0) Framed-IP-Address = 100.64.20.144 (0) Finished request Waking up in 4.9 seconds. (0) Cleaning up request packet ID 185 with timestamp +206 Ready to process requests Enviado do Email<https://go.microsoft.com/fwlink/?LinkId=550986> para Windows De: Jonathan Davis<mailto:jonathan@prioritycolo.com> Enviado:sábado, 3 de setembro de 2022 11:26 Para: FreeRadius users mailing list<mailto:freeradius-users@lists.freeradius.org> Assunto: Re: RES: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct If you do a tcpdump on the radius server, are you seeing accounting packets arriving on port 1813 from 10.5.5.17 ?
On Sep 3, 2022, at 10:15 AM, Pedro Daniel Costa <portalnet2@outlook.com.br> wrote:
As I said, you need to configure your NAS (the device with IP 10.5.5.17) to send accounting packets. No amount of configuring FreeRADIUS will fix this.
Ok i think i understood now what you meant with device with ip 10.5.5.17 , you meant my hardware radius server (my mikrotik test device) Yes i did check this yesterday and its enabled.. on accounting port 1813 - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Again, run a tcpdump to see what's going on. Freeradius isn't seeing
accounting packets, why is that? Are they getting dropped, or are they
not being sent?
Once you know this you can continue troubleshooting, e.g. opening ports
on a firewall, checking the NAS to figure out why it is not sending
accounting backings. As Matthew said, no amount of configuring
FreeRadius will resolve this if nothing is being received by FreeRadius.
Regards,
Jonathan Davis - Priority Colo Inc.
On 2022-09-03 10:34 a.m., Pedro Daniel Costa wrote:
> Thats the problem, o freeradius -x no accounting shown on the log all i can see is on init modules and accounting being loaded.. but when device connects.. only radipool gets updated..
>
> As shown on log below once freeradius reveices request from my radius server mikrotik device
>
>
> Ready to process requests
> (0) Received Access-Request Id 185 from 1.5.5.17:47154 to 10.5.5.200:1812 length 196
> (0) Service-Type = Framed-User
> (0) Framed-Protocol = PPP
> (0) NAS-Port = 15751547
> (0) NAS-Port-Type = Ethernet
> (0) User-Name = "ispteste200"
> (0) Calling-Station-Id = "80:8F:E8:F2:73:DB"
> (0) Called-Station-Id = "PPPOE-FIBRA"
> (0) NAS-Port-Id = "VLAN1250 - FIBRA PPPOE-PONTAL"
> (0) Acct-Session-Id = "81e05971"
> (0) CHAP-Challenge = 0xc602bf8d4fbf361e9d3746f5ae6dbe1e
> (0) CHAP-Password = 0x011b258f5bb0b1aad089ab2593de5d2fab
> (0) NAS-Identifier = "ROUTER P0NT4L PPP0E 2"
> (0) NAS-IP-Address = 1.5.5.17
> (0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default
> (0) authorize {
> (0) chap: &control:Auth-Type := CHAP
> (0) [chap] = ok
> (0) [mschap] = noop
> (0) eap: No EAP-Message, not doing EAP
> (0) [eap] = noop
> (0) sql: EXPAND %{User-Name}
> (0) sql: --> ispteste200
> (0) sql: SQL-User-Name set to 'ispteste200'
> rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 206 seconds
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 206 seconds
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 206 seconds
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 206 seconds
> rlm_sql (sql): You probably need to lower "min"
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 206 seconds
> rlm_sql (sql): You probably need to lower "min"
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 206 seconds
> rlm_sql (sql): You probably need to lower "min"
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare"
> rlm_sql (sql): Opening additional connection (6), 1 of 32 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
> rlm_sql (sql): Reserved connection (6)
> (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
> (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ispteste200' ORDER BY id
> (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ispteste200' ORDER BY id
> (0) sql: User found in radcheck table
> (0) sql: Conditional check items matched, merging assignment check items
> (0) sql: Cleartext-Password := "123123"
> (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
> (0) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ispteste200' ORDER BY id
> (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ispteste200' ORDER BY id
> rlm_sql (sql): 1 of 1 connections in use. You may need to increase "spare"
> rlm_sql (sql): Opening additional connection (7), 1 of 31 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
> rlm_sql (sql): Reserved connection (7)
> rlm_sql (sql): Released connection (7)
> Need 1 more connections to reach min connections (3)
> rlm_sql (sql): Opening additional connection (8), 1 of 30 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
> (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority
> (0) sql: --> SELECT groupname FROM radusergroup WHERE username = 'ispteste200' ORDER BY priority
> (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'ispteste200' ORDER BY priority
> (0) sql: User found in the group table
> (0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
> (0) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Group "fibra_50": Conditional check items matched
> (0) sql: Group "fibra_50": Merging assignment check items
> (0) sql: Framed-Protocol := PPP
> (0) sql: Pool-Name := "pool_pontal"
> (0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
> (0) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Group "fibra_50": Merging reply items
> (0) sql: Mikrotik-Rate-Limit := "500M/500M"
> (0) sql: Acct-Interim-Interval := 300
> (0) sql: MS-Primary-DNS-Server := 192.168.10.10
> (0) sql: MS-Secondary-DNS-Server := 192.168.10.11
> rlm_sql (sql): Released connection (6)
> (0) [sql] = ok
> (0) [expiration] = noop
> (0) [logintime] = noop
> (0) } # authorize = ok
> (0) Found Auth-Type = CHAP
> (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
> (0) Auth-Type CHAP {
> (0) chap: Comparing with "known good" Cleartext-Password
> (0) chap: CHAP user "ispteste200" authenticated successfully
> (0) [chap] = ok
> (0) } # Auth-Type CHAP = ok
> (0) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/default
> (0) post-auth {
> (0) update {
> (0) No attributes updated for RHS &session-state:
> (0) } # update = noop
> (0) sql: EXPAND .query
> (0) sql: --> .query
> (0) sql: Using query template 'query'
> rlm_sql (sql): Reserved connection (6)
> (0) sql: EXPAND %{User-Name}
> (0) sql: --> ispteste200
> (0) sql: SQL-User-Name set to 'ispteste200'
> (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
> (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ispteste200', '0x011b258f5bb0b1aad089ab2593de5d2fab', 'Access-Accept', '2022-09-03 10:54:19')
> (0) sql: EXPAND /var/log/freeradius/post-auth.sql
> (0) sql: --> /var/log/freeradius/post-auth.sql
> (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ispteste200', '0x011b258f5bb0b1aad089ab2593de5d2fab', 'Access-Accept', '2022-09-03 10:54:19')
> (0) sql: SQL query returned: success
> (0) sql: 1 record(s) updated
> rlm_sql (sql): Released connection (6)
> (0) [sql] = ok
> rlm_sql (sql): Reserved connection (7)
> (0) sqlippool: EXPAND %{User-Name}
> (0) sqlippool: --> ispteste200
> (0) sqlippool: SQL-User-Name set to 'ispteste200'
> (0) sqlippool: EXPAND START TRANSACTION
> (0) sqlippool: --> START TRANSACTION
> (0) sqlippool: Executing query: START TRANSACTION
> (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '%{Calling-Station-Id}'
> (0) sqlippool: --> UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8F:E8:F2:73:DB'
> (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8F:E8:F2:73:DB'
> rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0
> (0) sqlippool: EXPAND COMMIT
> (0) sqlippool: --> COMMIT
> (0) sqlippool: Executing query: COMMIT
> (0) sqlippool: EXPAND START TRANSACTION
> (0) sqlippool: --> START TRANSACTION
> (0) sqlippool: Executing query: START TRANSACTION
> (0) sqlippool: EXPAND SELECT framedipaddress FROM radippool WHERE pool_name = '%{control:Pool-Name}' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE
> (0) sqlippool: --> SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_pontal' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE
> (0) sqlippool: Executing select query: SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_pontal' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE
> (0) sqlippool: Allocated IP 100.64.20.144
> (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}', callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144'
> (0) sqlippool: --> UPDATE radippool SET nasipaddress = '1.5.5.17', pool_key = '80:8F:E8:F2:73:DB', callingstationid = '80:8F:E8:F2:73:DB', username = 'ispteste200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144'
> (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '1.5.5.17', pool_key = '80:8F:E8:F2:73:DB', callingstationid = '80:8F:E8:F2:73:DB', username = 'ispteste200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144'
> rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0
> (0) sqlippool: EXPAND COMMIT
> (0) sqlippool: --> COMMIT
> (0) sqlippool: Executing query: COMMIT
> rlm_sql (sql): Released connection (7)
> (0) sqlippool: EXPAND Allocated IP: %{reply:Framed-IP-Address} from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})
> (0) sqlippool: --> Allocated IP: 100.64.20.144 from pool_pontal (did PPPOE-FIBRA cli 80:8F:E8:F2:73:DB port 15751547 user ispteste200)
> (0) [sqlippool] = ok
> (0) policy remove_reply_message_if_eap {
> (0) if (&reply:EAP-Message && &reply:Reply-Message) {
> (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
> (0) else {
> (0) [noop] = noop
> (0) } # else = noop
> (0) } # policy remove_reply_message_if_eap = noop
> (0) } # post-auth = ok
> (0) Sent Access-Accept Id 185 from 10.5.5.200:1812 to 1.5.5.17:47154 length 0
> (0) Mikrotik-Rate-Limit = "500M/500M"
> (0) Acct-Interim-Interval = 300
> (0) MS-Primary-DNS-Server = 192.168.10.10
> (0) MS-Secondary-DNS-Server = 192.168.10.11
> (0) Framed-IP-Address = 100.64.20.144
> (0) Finished request
> Waking up in 4.9 seconds.
> (0) Cleaning up request packet ID 185 with timestamp +206
> Ready to process requests
>
>
> Enviado do Email<https://go.microsoft.com/fwlink/?LinkId=550986> para Windows
>
> De: Jonathan Davis<mailto:jonathan@prioritycolo.com>
> Enviado:sábado, 3 de setembro de 2022 11:26
> Para: FreeRadius users mailing list<mailto:freeradius-users@lists.freeradius.org>
> Assunto: Re: RES: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct
>
> If you do a tcpdump on the radius server, are you seeing accounting packets arriving on port 1813 from 10.5.5.17 ?
>
>> On Sep 3, 2022, at 10:15 AM, Pedro Daniel Costa <portalnet2@outlook.com.br> wrote:
>>
>>
>>
>> As I said, you need to configure your NAS (the device with IP 10.5.5.17)
>> to send accounting packets. No amount of configuring FreeRADIUS will fix
>> this.
>>
>>
>> Ok i think i understood now what you meant with device with ip 10.5.5.17 , you meant my hardware radius server (my mikrotik test device)
>> Yes i did check this yesterday and its enabled.. on accounting port 1813
>> -
>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Hi Jonathan, Matthew and all the other guys helping me on this subject..
first of all let me thank you all for your patience in trying to explain the newbie here..
in fact it was a (router device mikrotik config failure i had left accounting enabled on it.. but the update somehow was set to update every 5days instead of every 5minutes.. i would never figured it out if untill i double checked it again..
ok so i have gone one step further, now i can see the radacct update-interim sending data on the log, but its giving update sql fail.. log below described.. but looks like its something related to the nas port id.. which has a name of my vlan port looks like its too long i will try to set it something else and do a new check.
Ready to process requests
(0) Received Accounting-Request Id 195 from 10.5.5.17:50610 to 10.5.5.200:1813 length 61
(0) Acct-Status-Type = Accounting-On
(0) NAS-Identifier = "ROUTER P0NT4L PPP0E 2"
(0) Acct-Delay-Time = 0
(0) NAS-IP-Address = 10.5.5.17
(0) # Executing section preacct from file /etc/freeradius/3.0/sites-enabled/default
(0) preacct {
(0) policy acct_unique {
(0) update request {
(0) &Tmp-String-9 := "ai:"
(0) } # update request = noop
(0) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(0) EXPAND %{hex:&Class}
(0) -->
(0) EXPAND ^%{hex:&Tmp-String-9}
(0) --> ^61693a
(0) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
(0) else {
(0) update request {
(0) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(0) --> 12369f69a3d53cce0950d272fd455f2e
(0) &Acct-Unique-Session-Id := 12369f69a3d53cce0950d272fd455f2e
(0) } # update request = noop
(0) } # else = noop
(0) } # policy acct_unique = noop
(0) update request {
(0) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}}
(0) --> 1662219243
(0) &FreeRADIUS-Acct-Session-Start-Time = Sep 3 2022 12:34:03 -03
(0) } # update request = noop
(0) } # preacct = noop
(0) # Executing section accounting from file /etc/freeradius/3.0/sites-enabled/default
(0) accounting {
(0) sql: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(0) sql: --> type.accounting-on.query
(0) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (1)
(0) sql: EXPAND %{User-Name}
(0) sql: -->
(0) sql: SQL-User-Name set to ''
(0) sql: EXPAND 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})
(0) sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(), acctsessiontime = '' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = 'NAS-Reboot' WHERE acctstoptime IS NULL AND nasipaddress = '10.5.5.17' AND acctstarttime <= FROM_UNIXTIME()
(0) sql: EXPAND /var/log/freeradius/accounting.sql
(0) sql: --> /var/log/freeradius/accounting.sql
(0) sql: Executing query: UPDATE radacct SET acctstoptime = FROM_UNIXTIME(), acctsessiontime = '' - UNIX_TIMESTAMP(acctstarttime), acctterminatecause = 'NAS-Reboot' WHERE acctstoptime IS NULL AND nasipaddress = '10.5.5.17' AND acctstarttime <= FROM_UNIXTIME()
(0) sql: ERROR: rlm_sql_mysql: ERROR 1582 (Incorrect parameter count in the call to native function 'FROM_UNIXTIME'): 42000
(0) sql: SQL query returned: server error
rlm_sql (sql): Released connection (1)
Need 4 more connections to reach 10 spares
rlm_sql (sql): Opening additional connection (6), 1 of 26 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
(0) [sql] = fail
(0) } # accounting = fail
(0) Not sending reply to client.
(0) Finished request
(0) Cleaning up request packet ID 195 with timestamp +4
Ready to process requests
(1) Received Accounting-Request Id 196 from 10.5.5.17:43765 to 10.5.5.200:1813 length 284
(1) Service-Type = Framed-User
(1) Framed-Protocol = PPP
(1) NAS-Port = 15751564
(1) NAS-Port-Type = Ethernet
(1) User-Name = "ispteste200"
(1) Calling-Station-Id = "80:8F:E8:F2:73:DB"
(1) Called-Station-Id = "PPPOE-FIBRA"
(1) NAS-Port-Id = "VLAN1250 - FIBRA PPPOE-PONTAL"
(1) Acct-Session-Id = "81e05982"
(1) Framed-IP-Address = 100.64.20.144
(1) Acct-Authentic = RADIUS
(1) Event-Timestamp = "Sep 2 2022 13:16:17 -03"
(1) Acct-Session-Time = 54
(1) Idle-Timeout = 0
(1) Session-Timeout = 0
(1) X-Ascend-Data-Rate = 500000000
(1) Ascend-Xmit-Rate = 500000000
(1) Mikrotik-Rate-Limit = "500M/500M"
(1) Acct-Input-Octets = 6451
(1) Acct-Input-Gigawords = 0
(1) Acct-Input-Packets = 58
(1) Acct-Output-Octets = 11266
(1) Acct-Output-Gigawords = 0
(1) Acct-Output-Packets = 55
(1) Acct-Status-Type = Stop
(1) Acct-Terminate-Cause = User-Request
(1) NAS-Identifier = "ROUTER P0NT4L PPP0E 2"
(1) Acct-Delay-Time = 0
(1) NAS-IP-Address = 10.5.5.17
(1) # Executing section preacct from file /etc/freeradius/3.0/sites-enabled/default
(1) preacct {
(1) policy acct_unique {
(1) update request {
(1) &Tmp-String-9 := "ai:"
(1) } # update request = noop
(1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(1) EXPAND %{hex:&Class}
(1) -->
(1) EXPAND ^%{hex:&Tmp-String-9}
(1) --> ^61693a
(1) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) && ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
(1) else {
(1) update request {
(1) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(1) --> 36b328d576161a68a3d1ce1db12f88a4
(1) &Acct-Unique-Session-Id := 36b328d576161a68a3d1ce1db12f88a4
(1) } # update request = noop
(1) } # else = noop
(1) } # policy acct_unique = noop
(1) update request {
(1) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}}
(1) --> 1662219189
(1) &FreeRADIUS-Acct-Session-Start-Time = Sep 3 2022 12:33:09 -03
(1) } # update request = noop
(1) } # preacct = noop
(1) # Executing section accounting from file /etc/freeradius/3.0/sites-enabled/default
(1) accounting {
(1) sql: EXPAND %{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(1) sql: --> type.stop.query
(1) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (2)
(1) sql: EXPAND %{User-Name}
(1) sql: --> ispteste200
(1) sql: SQL-User-Name set to 'ispteste200'
(1) sql: EXPAND 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}'
(1) sql: --> UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1662135377), acctsessiontime = 54, acctinputoctets = '0' << 32 | '6451', acctoutputoctets = '0' << 32 | '11266', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE AcctUniqueId = '36b328d576161a68a3d1ce1db12f88a4'
(1) sql: EXPAND /var/log/freeradius/accounting.sql
(1) sql: --> /var/log/freeradius/accounting.sql
(1) sql: Executing query: UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1662135377), acctsessiontime = 54, acctinputoctets = '0' << 32 | '6451', acctoutputoctets = '0' << 32 | '11266', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE AcctUniqueId = '36b328d576161a68a3d1ce1db12f88a4'
rlm_sql_mysql: Rows matched: 0 Changed: 0 Warnings: 0
(1) sql: SQL query returned: success
(1) sql: 0 record(s) updated
(1) sql: Trying next query...
(1) sql: EXPAND 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}')
(1) sql: --> 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 ('81e05982', '36b328d576161a68a3d1ce1db12f88a4', 'ispteste200', '', '10.5.5.17', 'VLAN1250 - FIBRA PPPOE-PONTAL', 'Ethernet', FROM_UNIXTIME(1662135377 - 54), FROM_UNIXTIME(1662135377), FROM_UNIXTIME(1662135377), 54, 'RADIUS', '', '', '0' << 32 | '6451', '0' << 32 | '11266', 'PPPOE-FIBRA', '80:8F:E8:F2:73:DB', 'User-Request', 'Framed-User', 'PPP', '100.64.20.144', '', '', '', '')
(1) sql: EXPAND /var/log/freeradius/accounting.sql
(1) sql: --> /var/log/freeradius/accounting.sql
(1) sql: Executing 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 ('81e05982', '36b328d576161a68a3d1ce1db12f88a4', 'ispteste200', '', '10.5.5.17', 'VLAN1250 - FIBRA PPPOE-PONTAL', 'Ethernet', FROM_UNIXTIME(1662135377 - 54), FROM_UNIXTIME(1662135377), FROM_UNIXTIME(1662135377), 54, 'RADIUS', '', '', '0' << 32 | '6451', '0' << 32 | '11266', 'PPPOE-FIBRA', '80:8F:E8:F2:73:DB', 'User-Request', 'Framed-User', 'PPP', '100.64.20.144', '', '', '', '')
(1) sql: ERROR: rlm_sql_mysql: ERROR 1406 (Data too long for column 'nasportid' at row 1): 22001
(1) sql: SQL query returned: server error
rlm_sql (sql): Released connection (2)
(1) [sql] = fail
(1) } # accounting = fail
(1) Not sending reply to client.
(1) Finished request
(1) Cleaning up request packet ID 196 with timestamp +4
Enviado do Outlook<http://aka.ms/weboutlook>
________________________________
De: Freeradius-Users <freeradius-users-bounces+portalnet2=outlook.com.br@lists.freeradius.org> em nome de Jonathan Davis <jonathan@prioritycolo.com>
Enviado: sábado, 3 de setembro de 2022 12:07
Para: freeradius-users@lists.freeradius.org <freeradius-users@lists.freeradius.org>
Assunto: Re: RES: RES: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct
Again, run a tcpdump to see what's going on. Freeradius isn't seeing
accounting packets, why is that? Are they getting dropped, or are they
not being sent?
Once you know this you can continue troubleshooting, e.g. opening ports
on a firewall, checking the NAS to figure out why it is not sending
accounting backings. As Matthew said, no amount of configuring
FreeRadius will resolve this if nothing is being received by FreeRadius.
Regards,
Jonathan Davis - Priority Colo Inc.
On 2022-09-03 10:34 a.m., Pedro Daniel Costa wrote:
> Thats the problem, o freeradius -x no accounting shown on the log all i can see is on init modules and accounting being loaded.. but when device connects.. only radipool gets updated..
>
> As shown on log below once freeradius reveices request from my radius server mikrotik device
>
>
> Ready to process requests
> (0) Received Access-Request Id 185 from 1.5.5.17:47154 to 10.5.5.200:1812 length 196
> (0) Service-Type = Framed-User
> (0) Framed-Protocol = PPP
> (0) NAS-Port = 15751547
> (0) NAS-Port-Type = Ethernet
> (0) User-Name = "ispteste200"
> (0) Calling-Station-Id = "80:8F:E8:F2:73:DB"
> (0) Called-Station-Id = "PPPOE-FIBRA"
> (0) NAS-Port-Id = "VLAN1250 - FIBRA PPPOE-PONTAL"
> (0) Acct-Session-Id = "81e05971"
> (0) CHAP-Challenge = 0xc602bf8d4fbf361e9d3746f5ae6dbe1e
> (0) CHAP-Password = 0x011b258f5bb0b1aad089ab2593de5d2fab
> (0) NAS-Identifier = "ROUTER P0NT4L PPP0E 2"
> (0) NAS-IP-Address = 1.5.5.17
> (0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default
> (0) authorize {
> (0) chap: &control:Auth-Type := CHAP
> (0) [chap] = ok
> (0) [mschap] = noop
> (0) eap: No EAP-Message, not doing EAP
> (0) [eap] = noop
> (0) sql: EXPAND %{User-Name}
> (0) sql: --> ispteste200
> (0) sql: SQL-User-Name set to 'ispteste200'
> rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 206 seconds
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 206 seconds
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 206 seconds
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 206 seconds
> rlm_sql (sql): You probably need to lower "min"
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 206 seconds
> rlm_sql (sql): You probably need to lower "min"
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 206 seconds
> rlm_sql (sql): You probably need to lower "min"
> rlm_sql_mysql: Socket destructor called, closing socket
> rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare"
> rlm_sql (sql): Opening additional connection (6), 1 of 32 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
> rlm_sql (sql): Reserved connection (6)
> (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id
> (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ispteste200' ORDER BY id
> (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ispteste200' ORDER BY id
> (0) sql: User found in radcheck table
> (0) sql: Conditional check items matched, merging assignment check items
> (0) sql: Cleartext-Password := "123123"
> (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id
> (0) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ispteste200' ORDER BY id
> (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ispteste200' ORDER BY id
> rlm_sql (sql): 1 of 1 connections in use. You may need to increase "spare"
> rlm_sql (sql): Opening additional connection (7), 1 of 31 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
> rlm_sql (sql): Reserved connection (7)
> rlm_sql (sql): Released connection (7)
> Need 1 more connections to reach min connections (3)
> rlm_sql (sql): Opening additional connection (8), 1 of 30 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10
> (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority
> (0) sql: --> SELECT groupname FROM radusergroup WHERE username = 'ispteste200' ORDER BY priority
> (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'ispteste200' ORDER BY priority
> (0) sql: User found in the group table
> (0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id
> (0) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Group "fibra_50": Conditional check items matched
> (0) sql: Group "fibra_50": Merging assignment check items
> (0) sql: Framed-Protocol := PPP
> (0) sql: Pool-Name := "pool_pontal"
> (0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id
> (0) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fibra_50' ORDER BY id
> (0) sql: Group "fibra_50": Merging reply items
> (0) sql: Mikrotik-Rate-Limit := "500M/500M"
> (0) sql: Acct-Interim-Interval := 300
> (0) sql: MS-Primary-DNS-Server := 192.168.10.10
> (0) sql: MS-Secondary-DNS-Server := 192.168.10.11
> rlm_sql (sql): Released connection (6)
> (0) [sql] = ok
> (0) [expiration] = noop
> (0) [logintime] = noop
> (0) } # authorize = ok
> (0) Found Auth-Type = CHAP
> (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
> (0) Auth-Type CHAP {
> (0) chap: Comparing with "known good" Cleartext-Password
> (0) chap: CHAP user "ispteste200" authenticated successfully
> (0) [chap] = ok
> (0) } # Auth-Type CHAP = ok
> (0) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/default
> (0) post-auth {
> (0) update {
> (0) No attributes updated for RHS &session-state:
> (0) } # update = noop
> (0) sql: EXPAND .query
> (0) sql: --> .query
> (0) sql: Using query template 'query'
> rlm_sql (sql): Reserved connection (6)
> (0) sql: EXPAND %{User-Name}
> (0) sql: --> ispteste200
> (0) sql: SQL-User-Name set to 'ispteste200'
> (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')
> (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ispteste200', '0x011b258f5bb0b1aad089ab2593de5d2fab', 'Access-Accept', '2022-09-03 10:54:19')
> (0) sql: EXPAND /var/log/freeradius/post-auth.sql
> (0) sql: --> /var/log/freeradius/post-auth.sql
> (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ispteste200', '0x011b258f5bb0b1aad089ab2593de5d2fab', 'Access-Accept', '2022-09-03 10:54:19')
> (0) sql: SQL query returned: success
> (0) sql: 1 record(s) updated
> rlm_sql (sql): Released connection (6)
> (0) [sql] = ok
> rlm_sql (sql): Reserved connection (7)
> (0) sqlippool: EXPAND %{User-Name}
> (0) sqlippool: --> ispteste200
> (0) sqlippool: SQL-User-Name set to 'ispteste200'
> (0) sqlippool: EXPAND START TRANSACTION
> (0) sqlippool: --> START TRANSACTION
> (0) sqlippool: Executing query: START TRANSACTION
> (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '%{Calling-Station-Id}'
> (0) sqlippool: --> UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8F:E8:F2:73:DB'
> (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8F:E8:F2:73:DB'
> rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0
> (0) sqlippool: EXPAND COMMIT
> (0) sqlippool: --> COMMIT
> (0) sqlippool: Executing query: COMMIT
> (0) sqlippool: EXPAND START TRANSACTION
> (0) sqlippool: --> START TRANSACTION
> (0) sqlippool: Executing query: START TRANSACTION
> (0) sqlippool: EXPAND SELECT framedipaddress FROM radippool WHERE pool_name = '%{control:Pool-Name}' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE
> (0) sqlippool: --> SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_pontal' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE
> (0) sqlippool: Executing select query: SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_pontal' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE
> (0) sqlippool: Allocated IP 100.64.20.144
> (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}', callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144'
> (0) sqlippool: --> UPDATE radippool SET nasipaddress = '1.5.5.17', pool_key = '80:8F:E8:F2:73:DB', callingstationid = '80:8F:E8:F2:73:DB', username = 'ispteste200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144'
> (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '1.5.5.17', pool_key = '80:8F:E8:F2:73:DB', callingstationid = '80:8F:E8:F2:73:DB', username = 'ispteste200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144'
> rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0
> (0) sqlippool: EXPAND COMMIT
> (0) sqlippool: --> COMMIT
> (0) sqlippool: Executing query: COMMIT
> rlm_sql (sql): Released connection (7)
> (0) sqlippool: EXPAND Allocated IP: %{reply:Framed-IP-Address} from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})
> (0) sqlippool: --> Allocated IP: 100.64.20.144 from pool_pontal (did PPPOE-FIBRA cli 80:8F:E8:F2:73:DB port 15751547 user ispteste200)
> (0) [sqlippool] = ok
> (0) policy remove_reply_message_if_eap {
> (0) if (&reply:EAP-Message && &reply:Reply-Message) {
> (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
> (0) else {
> (0) [noop] = noop
> (0) } # else = noop
> (0) } # policy remove_reply_message_if_eap = noop
> (0) } # post-auth = ok
> (0) Sent Access-Accept Id 185 from 10.5.5.200:1812 to 1.5.5.17:47154 length 0
> (0) Mikrotik-Rate-Limit = "500M/500M"
> (0) Acct-Interim-Interval = 300
> (0) MS-Primary-DNS-Server = 192.168.10.10
> (0) MS-Secondary-DNS-Server = 192.168.10.11
> (0) Framed-IP-Address = 100.64.20.144
> (0) Finished request
> Waking up in 4.9 seconds.
> (0) Cleaning up request packet ID 185 with timestamp +206
> Ready to process requests
>
>
> Enviado do Email<https://go.microsoft.com/fwlink/?LinkId=550986> para Windows
>
> De: Jonathan Davis<mailto:jonathan@prioritycolo.com>
> Enviado:sábado, 3 de setembro de 2022 11:26
> Para: FreeRadius users mailing list<mailto:freeradius-users@lists.freeradius.org>
> Assunto: Re: RES: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct
>
> If you do a tcpdump on the radius server, are you seeing accounting packets arriving on port 1813 from 10.5.5.17 ?
>
>> On Sep 3, 2022, at 10:15 AM, Pedro Daniel Costa <portalnet2@outlook.com.br> wrote:
>>
>>
>>
>> As I said, you need to configure your NAS (the device with IP 10.5.5.17)
>> to send accounting packets. No amount of configuring FreeRADIUS will fix
>> this.
>>
>>
>> Ok i think i understood now what you meant with device with ip 10.5.5.17 , you meant my hardware radius server (my mikrotik test device)
>> Yes i did check this yesterday and its enabled.. on accounting port 1813
>> -
>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Guys .. all confirmed now everything working as expected i have increased the size value on the column nasportid inside radacct and its now storing the data sent from mikrotik sucessful. Once again thank you all for the support. Enviado do Outlook<http://aka.ms/weboutlook> ________________________________ De: Freeradius-Users <freeradius-users-bounces+portalnet2=outlook.com.br@lists.freeradius.org> em nome de Pedro Daniel Costa <portalnet2@outlook.com.br> Enviado: sábado, 3 de setembro de 2022 11:34 Para: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Assunto: RES: RES: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct Thats the problem, o freeradius -x no accounting shown on the log all i can see is on init modules and accounting being loaded.. but when device connects.. only radipool gets updated.. As shown on log below once freeradius reveices request from my radius server mikrotik device Ready to process requests (0) Received Access-Request Id 185 from 1.5.5.17:47154 to 10.5.5.200:1812 length 196 (0) Service-Type = Framed-User (0) Framed-Protocol = PPP (0) NAS-Port = 15751547 (0) NAS-Port-Type = Ethernet (0) User-Name = "ispteste200" (0) Calling-Station-Id = "80:8F:E8:F2:73:DB" (0) Called-Station-Id = "PPPOE-FIBRA" (0) NAS-Port-Id = "VLAN1250 - FIBRA PPPOE-PONTAL" (0) Acct-Session-Id = "81e05971" (0) CHAP-Challenge = 0xc602bf8d4fbf361e9d3746f5ae6dbe1e (0) CHAP-Password = 0x011b258f5bb0b1aad089ab2593de5d2fab (0) NAS-Identifier = "ROUTER P0NT4L PPP0E 2" (0) NAS-IP-Address = 1.5.5.17 (0) # Executing section authorize from file /etc/freeradius/3.0/sites-enabled/default (0) authorize { (0) chap: &control:Auth-Type := CHAP (0) [chap] = ok (0) [mschap] = noop (0) eap: No EAP-Message, not doing EAP (0) [eap] = noop (0) sql: EXPAND %{User-Name} (0) sql: --> ispteste200 (0) sql: SQL-User-Name set to 'ispteste200' rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 206 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 206 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 206 seconds rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 206 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 206 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 206 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare" rlm_sql (sql): Opening additional connection (6), 1 of 32 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Reserved connection (6) (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (0) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ispteste200' ORDER BY id (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ispteste200' ORDER BY id (0) sql: User found in radcheck table (0) sql: Conditional check items matched, merging assignment check items (0) sql: Cleartext-Password := "123123" (0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (0) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ispteste200' ORDER BY id (0) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ispteste200' ORDER BY id rlm_sql (sql): 1 of 1 connections in use. You may need to increase "spare" rlm_sql (sql): Opening additional connection (7), 1 of 31 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 rlm_sql (sql): Reserved connection (7) rlm_sql (sql): Released connection (7) Need 1 more connections to reach min connections (3) rlm_sql (sql): Opening additional connection (8), 1 of 30 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.5.5-10.3.34-MariaDB-0ubuntu0.20.04.1, protocol version 10 (0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority (0) sql: --> SELECT groupname FROM radusergroup WHERE username = 'ispteste200' ORDER BY priority (0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE username = 'ispteste200' ORDER BY priority (0) sql: User found in the group table (0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id (0) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fibra_50' ORDER BY id (0) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'fibra_50' ORDER BY id (0) sql: Group "fibra_50": Conditional check items matched (0) sql: Group "fibra_50": Merging assignment check items (0) sql: Framed-Protocol := PPP (0) sql: Pool-Name := "pool_pontal" (0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id (0) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fibra_50' ORDER BY id (0) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'fibra_50' ORDER BY id (0) sql: Group "fibra_50": Merging reply items (0) sql: Mikrotik-Rate-Limit := "500M/500M" (0) sql: Acct-Interim-Interval := 300 (0) sql: MS-Primary-DNS-Server := 192.168.10.10 (0) sql: MS-Secondary-DNS-Server := 192.168.10.11 rlm_sql (sql): Released connection (6) (0) [sql] = ok (0) [expiration] = noop (0) [logintime] = noop (0) } # authorize = ok (0) Found Auth-Type = CHAP (0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default (0) Auth-Type CHAP { (0) chap: Comparing with "known good" Cleartext-Password (0) chap: CHAP user "ispteste200" authenticated successfully (0) [chap] = ok (0) } # Auth-Type CHAP = ok (0) # Executing section post-auth from file /etc/freeradius/3.0/sites-enabled/default (0) post-auth { (0) update { (0) No attributes updated for RHS &session-state: (0) } # update = noop (0) sql: EXPAND .query (0) sql: --> .query (0) sql: Using query template 'query' rlm_sql (sql): Reserved connection (6) (0) sql: EXPAND %{User-Name} (0) sql: --> ispteste200 (0) sql: SQL-User-Name set to 'ispteste200' (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ispteste200', '0x011b258f5bb0b1aad089ab2593de5d2fab', 'Access-Accept', '2022-09-03 10:54:19') (0) sql: EXPAND /var/log/freeradius/post-auth.sql (0) sql: --> /var/log/freeradius/post-auth.sql (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ispteste200', '0x011b258f5bb0b1aad089ab2593de5d2fab', 'Access-Accept', '2022-09-03 10:54:19') (0) sql: SQL query returned: success (0) sql: 1 record(s) updated rlm_sql (sql): Released connection (6) (0) [sql] = ok rlm_sql (sql): Reserved connection (7) (0) sqlippool: EXPAND %{User-Name} (0) sqlippool: --> ispteste200 (0) sqlippool: SQL-User-Name set to 'ispteste200' (0) sqlippool: EXPAND START TRANSACTION (0) sqlippool: --> START TRANSACTION (0) sqlippool: Executing query: START TRANSACTION (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '%{Calling-Station-Id}' (0) sqlippool: --> UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8F:E8:F2:73:DB' (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE pool_key = '80:8F:E8:F2:73:DB' rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0 (0) sqlippool: EXPAND COMMIT (0) sqlippool: --> COMMIT (0) sqlippool: Executing query: COMMIT (0) sqlippool: EXPAND START TRANSACTION (0) sqlippool: --> START TRANSACTION (0) sqlippool: Executing query: START TRANSACTION (0) sqlippool: EXPAND SELECT framedipaddress FROM radippool WHERE pool_name = '%{control:Pool-Name}' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE (0) sqlippool: --> SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_pontal' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE (0) sqlippool: Executing select query: SELECT framedipaddress FROM radippool WHERE pool_name = 'pool_pontal' AND expiry_time IS NULL ORDER BY RAND() LIMIT 1 FOR UPDATE (0) sqlippool: Allocated IP 100.64.20.144 (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}', callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144' (0) sqlippool: --> UPDATE radippool SET nasipaddress = '1.5.5.17', pool_key = '80:8F:E8:F2:73:DB', callingstationid = '80:8F:E8:F2:73:DB', username = 'ispteste200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144' (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '1.5.5.17', pool_key = '80:8F:E8:F2:73:DB', callingstationid = '80:8F:E8:F2:73:DB', username = 'ispteste200', expiry_time = NOW() + INTERVAL 1600 SECOND WHERE framedipaddress = '100.64.20.144' rlm_sql_mysql: Rows matched: 1 Changed: 1 Warnings: 0 (0) sqlippool: EXPAND COMMIT (0) sqlippool: --> COMMIT (0) sqlippool: Executing query: COMMIT rlm_sql (sql): Released connection (7) (0) sqlippool: EXPAND Allocated IP: %{reply:Framed-IP-Address} from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name}) (0) sqlippool: --> Allocated IP: 100.64.20.144 from pool_pontal (did PPPOE-FIBRA cli 80:8F:E8:F2:73:DB port 15751547 user ispteste200) (0) [sqlippool] = ok (0) policy remove_reply_message_if_eap { (0) if (&reply:EAP-Message && &reply:Reply-Message) { (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (0) else { (0) [noop] = noop (0) } # else = noop (0) } # policy remove_reply_message_if_eap = noop (0) } # post-auth = ok (0) Sent Access-Accept Id 185 from 10.5.5.200:1812 to 1.5.5.17:47154 length 0 (0) Mikrotik-Rate-Limit = "500M/500M" (0) Acct-Interim-Interval = 300 (0) MS-Primary-DNS-Server = 192.168.10.10 (0) MS-Secondary-DNS-Server = 192.168.10.11 (0) Framed-IP-Address = 100.64.20.144 (0) Finished request Waking up in 4.9 seconds. (0) Cleaning up request packet ID 185 with timestamp +206 Ready to process requests Enviado do Email<https://go.microsoft.com/fwlink/?LinkId=550986> para Windows De: Jonathan Davis<mailto:jonathan@prioritycolo.com> Enviado:sábado, 3 de setembro de 2022 11:26 Para: FreeRadius users mailing list<mailto:freeradius-users@lists.freeradius.org> Assunto: Re: RES: Freeradius 3.0.20 Fresh Install not storing radacct logs in mysql table radacct If you do a tcpdump on the radius server, are you seeing accounting packets arriving on port 1813 from 10.5.5.17 ?
On Sep 3, 2022, at 10:15 AM, Pedro Daniel Costa <portalnet2@outlook.com.br> wrote:
As I said, you need to configure your NAS (the device with IP 10.5.5.17) to send accounting packets. No amount of configuring FreeRADIUS will fix this.
Ok i think i understood now what you meant with device with ip 10.5.5.17 , you meant my hardware radius server (my mikrotik test device) Yes i did check this yesterday and its enabled.. on accounting port 1813 - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
participants (3)
-
Jonathan Davis -
Matthew Newton -
Pedro Daniel Costa