Why is not writting in second detail file?
I have defined a second detail file writer that functions correct writting a second file. When I define in radiusd.conf this code: server radiusB { listen { type = detail filename = /var/log/freeradius/radacct/second_detail load_factor = 25 } preacct { preprocess suffix } accounting { ok } pre-proxy { } post-proxy { } } Writer doesn't writes to the file. I don't know why. If I comment the previous code, function correctly. I have configured in proxy.conf my home server. So, when reader try to reads records from second detail file, this file not exists. Output: FreeRADIUS Version 2.1.10, for host i486-pc-linux-gnu, built on Nov 14 2010 at 20:41:03 Copyright (C) 1999-2009 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 v2. Starting - reading configuration files ... including configuration file /etc/freeradius/radiusd.conf including configuration file /etc/freeradius/clients.conf including files in directory /etc/freeradius/modules/ including configuration file /etc/freeradius/modules/ntlm_auth including configuration file /etc/freeradius/modules/linelog including configuration file /etc/freeradius/modules/radutmp including configuration file /etc/freeradius/modules/echo including configuration file /etc/freeradius/modules/attr_rewrite including configuration file /etc/freeradius/modules/ippool including configuration file /etc/freeradius/modules/mac2ip including configuration file /etc/freeradius/modules/counter including configuration file /etc/freeradius/modules/detail_ori including configuration file /etc/freeradius/modules/sqlcounter_expire_on_login including configuration file /etc/freeradius/modules/logintime including configuration file /etc/freeradius/modules/detail including configuration file /etc/freeradius/modules/realm including configuration file /etc/freeradius/modules/expr including configuration file /etc/freeradius/modules/otp including configuration file /etc/freeradius/modules/etc_group including configuration file /etc/freeradius/modules/digest including configuration file /etc/freeradius/modules/sql_log including configuration file /etc/freeradius/modules/preprocess including configuration file /etc/freeradius/modules/inner-eap including configuration file /etc/freeradius/modules/sradutmp including configuration file /etc/freeradius/modules/passwd including configuration file /etc/freeradius/modules/detail.example.com including configuration file /etc/freeradius/modules/krb5 including configuration file /etc/freeradius/modules/expiration including configuration file /etc/freeradius/modules/checkval including configuration file /etc/freeradius/modules/smbpasswd including configuration file /etc/freeradius/modules/perl including configuration file /etc/freeradius/modules/cui including configuration file /etc/freeradius/modules/mac2vlan including configuration file /etc/freeradius/modules/pam including configuration file /etc/freeradius/modules/opendirectory including configuration file /etc/freeradius/modules/dynamic_clients including configuration file /etc/freeradius/modules/smsotp including configuration file /etc/freeradius/modules/unix including configuration file /etc/freeradius/modules/always including configuration file /etc/freeradius/modules/policy including configuration file /etc/freeradius/modules/ldap including configuration file /etc/freeradius/modules/detail.log including configuration file /etc/freeradius/modules/acct_unique including configuration file /etc/freeradius/modules/files including configuration file /etc/freeradius/modules/exec including configuration file /etc/freeradius/modules/wimax including configuration file /etc/freeradius/modules/chap including configuration file /etc/freeradius/modules/attr_filter including configuration file /etc/freeradius/modules/pap including configuration file /etc/freeradius/modules/mschap including configuration file /etc/freeradius/eap.conf including configuration file /etc/freeradius/sql.conf including configuration file /etc/freeradius/sql/mysql/dialup.conf including configuration file /etc/freeradius/policy.conf including files in directory /etc/freeradius/sites-enabled/ including configuration file /etc/freeradius/sites-enabled/inner-tunnel including configuration file /etc/freeradius/sites-enabled/default main { user = "freerad" group = "freerad" allow_core_dumps = no } including dictionary file /etc/freeradius/dictionary main { prefix = "/usr" localstatedir = "/var" logdir = "/var/log/freeradius" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/freeradius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 1024 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 } security { max_attributes = 200 reject_delay = 1 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### radiusd: #### Loading Clients #### client localhost { ipaddr = 127.0.0.1 require_message_authenticator = no secret = "testing123" nastype = "other" } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating module "exec" from file /etc/freeradius/modules/exec exec { wait = no input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_expr Module: Instantiating module "expr" from file /etc/freeradius/modules/expr Module: Linked to module rlm_expiration Module: Instantiating module "expiration" from file /etc/freeradius/modules/expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating module "logintime" from file /etc/freeradius/modules/logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel modules { Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating module "pap" from file /etc/freeradius/modules/pap pap { encryption_scheme = "auto" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating module "chap" from file /etc/freeradius/modules/chap Module: Linked to module rlm_mschap Module: Instantiating module "mschap" from file /etc/freeradius/modules/mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = no } Module: Linked to module rlm_unix Module: Instantiating module "unix" from file /etc/freeradius/modules/unix unix { radwtmp = "/var/log/freeradius/radwtmp" } Module: Linked to module rlm_eap Module: Instantiating module "eap" from file /etc/freeradius/eap.conf eap { default_eap_type = "md5" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 4096 } Module: Linked to sub-module rlm_eap_md5 Module: Instantiating eap-md5 Module: Linked to sub-module rlm_eap_leap Module: Instantiating eap-leap Module: Linked to sub-module rlm_eap_gtc Module: Instantiating eap-gtc gtc { challenge = "Password: " auth_type = "PAP" } Module: Linked to sub-module rlm_eap_tls Module: Instantiating eap-tls tls { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 CA_path = "/etc/freeradius/certs" pem_file_type = yes private_key_file = "/etc/freeradius/certs/server.key" certificate_file = "/etc/freeradius/certs/server.pem" CA_file = "/etc/freeradius/certs/ca.pem" private_key_password = "whatever" dh_file = "/etc/freeradius/certs/dh" random_file = "/dev/urandom" fragment_size = 1024 include_length = yes check_crl = no cipher_list = "DEFAULT" make_cert_command = "/etc/freeradius/certs/bootstrap" cache { enable = no lifetime = 24 max_entries = 255 } verify { } } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { default_eap_type = "md5" copy_request_to_tunnel = no use_tunneled_reply = no virtual_server = "inner-tunnel" include_length = yes } Module: Linked to sub-module rlm_eap_peap Module: Instantiating eap-peap peap { default_eap_type = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" } Module: Linked to sub-module rlm_eap_mschapv2 Module: Instantiating eap-mschapv2 mschapv2 { with_ntdomain_hack = no } Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_realm Module: Instantiating module "suffix" from file /etc/freeradius/modules/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } Module: Linked to module rlm_files Module: Instantiating module "files" from file /etc/freeradius/modules/files files { usersfile = "/etc/freeradius/users" acctusersfile = "/etc/freeradius/acct_users" preproxy_usersfile = "/etc/freeradius/preproxy_users" compat = "no" } Module: Checking session {...} for more modules to load Module: Linked to module rlm_radutmp Module: Instantiating module "radutmp" from file /etc/freeradius/modules/radutmp radutmp { filename = "/var/log/freeradius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load Module: Linked to module rlm_attr_filter Module: Instantiating module "attr_filter.access_reject" from file /etc/freeradius/modules/attr_filter attr_filter attr_filter.access_reject { attrsfile = "/etc/freeradius/attrs.access_reject" key = "%{User-Name}" } } # modules } # server server replicatedRadius { # from file /etc/freeradius/radiusd.conf modules { Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_preprocess Module: Instantiating module "preprocess" from file /etc/freeradius/modules/preprocess preprocess { huntgroups = "/etc/freeradius/huntgroups" hints = "/etc/freeradius/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 } Module: Checking accounting {...} for more modules to load Module: Linked to module rlm_always Module: Instantiating module "ok" from file /etc/freeradius/modules/always always ok { rcode = "ok" simulcount = 0 mpp = no } } # modules } # server server { # from file /etc/freeradius/radiusd.conf modules { Module: Checking authenticate {...} for more modules to load Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_sql Module: Instantiating module "sql" from file /etc/freeradius/sql.conf sql { driver = "rlm_sql_mysql" server = "localhost" port = "" login = "radius" password = "radpass" radius_db = "radius" read_groups = yes sqltrace = no sqltracefile = "/var/log/freeradius/sqltrace.sql" readclients = yes deletestalesessions = yes num_sql_socks = 5 lifetime = 0 max_queries = 0 sql_user_name = "%{User-Name}" default_user_profile = "" nas_query = "SELECT id, nasname, shortname, type, secret, server FROM nas" authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id" authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id" authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id" authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id" accounting_onoff_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = unix_timestamp('%S') - unix_timestamp(acctstarttime), acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = %{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= '%S'" accounting_update_query = " UPDATE radacct SET framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" accounting_update_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctsessiontime, acctauthentic, connectinfo_start, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, servicetype, framedprotocol, framedipaddress, acctstartdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{X-Ascend-Session-Svr-Key}')" accounting_start_query = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')" accounting_start_query_alt = " UPDATE radacct SET acctstarttime = '%S', acctstartdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_start = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" accounting_stop_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" accounting_stop_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{%{Acct-Delay-Time}:-0}')" group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" connect_failure_retry_delay = 60 simul_count_query = "" simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" } rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked rlm_sql (sql): Attempting to connect to radius@localhost:/radius rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 rlm_sql_mysql: Starting connect to MySQL server for #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 rlm_sql_mysql: Starting connect to MySQL server for #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 rlm_sql_mysql: Starting connect to MySQL server for #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 rlm_sql_mysql: Starting connect to MySQL server for #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 rlm_sql_mysql: Starting connect to MySQL server for #4 rlm_sql (sql): Connected new DB handle, #4 rlm_sql (sql): 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): Reserving sql socket id: 4 rlm_sql (sql): Read entry nasname=192.168.1.7,shortname=localpc,secret=machine rlm_sql (sql): Adding client 192.168.1.7 (localpc, server=<none>) to clients list rlm_sql (sql): Read entry nasname=192.168.1.163,shortname=kioscopc,secret=kioscos rlm_sql (sql): Adding client 192.168.1.163 (kioscopc, server=<none>) to clients list rlm_sql (sql): Released sql socket id: 4 Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: Instantiating module "acct_unique" from file /etc/freeradius/modules/acct_unique acct_unique { key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" } Module: Checking accounting {...} for more modules to load Module: Linked to module rlm_detail Module: Instantiating module "detail" from file /etc/freeradius/modules/detail_ori detail { detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Instantiating module "second_detail" from file /etc/freeradius/modules/detail detail second_detail { detailfile = "/var/log/freeradius/radacct/second_detail" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/modules/attr_filter attr_filter attr_filter.accounting_response { attrsfile = "/etc/freeradius/attrs.accounting_response" key = "%{User-Name}" } Module: Checking session {...} for more modules to load Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load } # modules } # server radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = * port = 1812 } listen { type = "acct" ipaddr = * port = 1813 } listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } listen { type = "detail" listen { filename = "/var/log/freeradius/radacct/second_detail" load_factor = 25 poll_interval = 1 retry_interval = 30 } } Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Listening on detail file /var/log/freeradius/radacct/second_detail as server replicatedRadius Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 1.000000 sec Listening on proxy address * port 1814 Waking up in 0.9 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.826187 sec Waking up in 0.8 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.880263 sec Waking up in 0.8 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.976768 sec Waking up in 0.9 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.845203 sec Waking up in 0.8 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 1.224813 sec Waking up in 1.2 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 1.246018 sec Waking up in 1.2 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 1.151570 sec Waking up in 1.1 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.961201 sec Waking up in 0.9 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.793563 sec Waking up in 0.7 seconds. rad_recv: Access-Request packet from host 192.168.1.7 port 64638, id=36, length=118 User-Name = "probador" Acct-Session-Id = "1319530770S3ane" NAS-IP-Address = 127.0.0.1 NAS-Identifier = "Localhost" NAS-Port = 0 Calling-Station-Id = "1115551212" User-Password = "probadorpass" Message-Authenticator = 0x2288b8da08cda6df3e989c63e561cc61 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop [suffix] No '@' in User-Name = "probador", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop ++[files] returns noop [sql] expand: %{User-Name} -> probador [sql] sql_set_user escaped user --> 'probador' rlm_sql (sql): Reserving sql socket id: 3 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'probador' ORDER BY id WARNING: Found User-Password == "...". WARNING: Are you sure you don't mean Cleartext-Password? WARNING: See "man rlm_pap" for more information. [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'probador' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'probador' ORDER BY priority rlm_sql (sql): Released sql socket id: 3 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop ++[pap] returns updated Found Auth-Type = PAP !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! !!! Replacing User-Password in config items with Cleartext-Password. !!! !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! !!! Please update your configuration so that the "known good" !!! !!! clear text password is in Cleartext-Password, and not in User-Password. !!! !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! # Executing group from file /etc/freeradius/sites-enabled/default +- entering group PAP {...} [pap] login attempt with password "probadorpass" [pap] Using clear text password "probadorpass" [pap] User authenticated successfully ++[pap] returns ok # Executing section post-auth from file /etc/freeradius/sites-enabled/default +- entering group post-auth {...} ++[exec] returns noop Sending Access-Accept of id 36 to 192.168.1.7 port 64638 Finished request 0. Going to the next request Waking up in 0.6 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.885732 sec Waking up in 0.8 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.912520 sec Waking up in 0.9 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 1.193714 sec Waking up in 1.1 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.805761 sec Waking up in 0.8 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 1.145429 sec Waking up in 0.5 seconds. Cleaning up request 0 ID 36 with timestamp +9 Waking up in 0.6 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.955676 sec Waking up in 0.9 seconds. rad_recv: Accounting-Request packet from host 192.168.1.7 port 64639, id=37, length=101 User-Name = "probador" Acct-Session-Id = "1319530776V34yzo" NAS-IP-Address = 127.0.0.1 NAS-Identifier = "Localhost" NAS-Port = 0 Calling-Station-Id = "1115551212" Acct-Status-Type = Stop Acct-Session-Time = 180 Acct-Delay-Time = 1 # Executing section preacct from file /etc/freeradius/sites-enabled/default +- entering group preacct {...} ++[preprocess] returns ok [acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.1.7,NAS-IP-Address = 127.0.0.1,Acct-Session-Id = "1319530776V34yzo",User-Name = "probador"' [acct_unique] Acct-Unique-Session-ID = "7fca33c18994b4b7". ++[acct_unique] returns ok [suffix] No '@' in User-Name = "probador", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop ++[files] returns noop # Executing section accounting from file /etc/freeradius/sites-enabled/default +- entering group accounting {...} [detail] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/192.168.1.7/detail-20111025 [detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.1.7/detail-20111025 [detail] expand: %t -> Tue Oct 25 10:19:36 2011 ++[detail] returns ok [second_detail] expand: /var/log/freeradius/radacct/second_detail -> /var/log/freeradius/radacct/second_detail [second_detail] /var/log/freeradius/radacct/second_detail expands to /var/log/freeradius/radacct/second_detail [second_detail] expand: %t -> Tue Oct 25 10:19:36 2011 ++[second_detail] returns ok ++[unix] returns ok [radutmp] expand: /var/log/freeradius/radutmp -> /var/log/freeradius/radutmp [radutmp] expand: %{User-Name} -> probador rlm_radutmp: Logout for NAS 127.0.0.1 port 0, but no Login record ++[radutmp] returns ok [sql] expand: %{User-Name} -> probador [sql] sql_set_user escaped user --> 'probador' [sql] expand: %{Acct-Input-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Input-Octets} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Output-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Output-Octets} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Delay-Time} -> 1 [sql] expand: UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}' -> UPDATE radacct SET acctstoptime = '2011-10-25 10:19:36', acctsessiontime = '180', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | rlm_sql (sql): Reserving sql socket id: 2 [sql] expand: %{Acct-Session-Time} -> 180 [sql] expand: %{Acct-Delay-Time} -> 1 [sql] expand: %{Acct-Input-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Input-Octets} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Output-Gigawords} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Output-Octets} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Delay-Time} -> 1 [sql] expand: INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Inpu rlm_sql (sql): Released sql socket id: 2 ++[sql] returns ok ++[exec] returns noop [attr_filter.accounting_response] expand: %{User-Name} -> probador attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 37 to 192.168.1.7 port 64639 Finished request 1. Cleaning up request 1 ID 37 with timestamp +16 Going to the next request Waking up in 0.3 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail - Renaming /var/log/freeradius/radacct/second_detail -> /var/log/freeradius/radacct/second_detail.work detail_recv: Read packet from /var/log/freeradius/radacct/second_detail.work User-Name = "probador" Acct-Session-Id = "1319530776V34yzo" NAS-IP-Address = 127.0.0.1 NAS-Identifier = "Localhost" NAS-Port = 0 Calling-Station-Id = "1115551212" Acct-Status-Type = Stop Acct-Session-Time = 180 Acct-Delay-Time = 1 Acct-Unique-Session-Id = "7fca33c18994b4b7" Packet-Original-Timestamp = "Oct 25 2011 10:19:36 CEST" Packet-Transmit-Counter = 1 server replicatedRadius { # Executing section preacct from file /etc/freeradius/radiusd.conf +- entering group preacct {...} ++[preprocess] returns ok [suffix] No '@' in User-Name = "probador", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop # Executing section accounting from file /etc/freeradius/radiusd.conf +- entering group accounting {...} ++[ok] returns ok } # server replicatedRadius Finished request 2. Cleaning up request 2 ID 6568 with timestamp +16 Going to the next request Detail listener /var/log/freeradius/radacct/second_detail state replied signalled 0 waiting 0.001929 sec Detail - unlinking /var/log/freeradius/radacct/second_detail.work Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.811150 sec Waking up in 0.8 seconds. Waking up in 0.8 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 1.170832 sec Waking up in 1.1 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 0.852104 sec Waking up in 0.8 seconds. Polling for detail file /var/log/freeradius/radacct/second_detail Detail listener /var/log/freeradius/radacct/second_detail state unopened signalled 0 waiting 1.081467 sec Waking up in 1.0 seconds. Can you help me? Thanks. -- View this message in context: http://freeradius.1045715.n5.nabble.com/Why-is-not-writting-in-second-detail... Sent from the FreeRadius - User mailing list archive at Nabble.com.
On Tue, Oct 25, 2011 at 3:30 PM, tonimanel <antoniofernandez@fabergames.com> wrote:
I have defined a second detail file writer that functions correct writting a second file. When I define in radiusd.conf this code:
server radiusB { listen { type = detail filename = /var/log/freeradius/radacct/second_detail load_factor = 25 }
This is a READER.
Writer doesn't writes to the file.
First thing to check is whether you have a second instance of rlm_detail that WRITES to that file.
Module: Instantiating module "second_detail" from file /etc/freeradius/modules/detail detail second_detail { detailfile = "/var/log/freeradius/radacct/second_detail" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no }
... and apparently you do. That was the instantiation part ...
+- entering group accounting {...} [detail] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d -> /var/log/freeradius/radacct/192.168.1.7/detail-20111025 [detail] /var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.1.7/detail-20111025 [detail] expand: %t -> Tue Oct 25 10:19:36 2011 ++[detail] returns ok [second_detail] expand: /var/log/freeradius/radacct/second_detail -> /var/log/freeradius/radacct/second_detail [second_detail] /var/log/freeradius/radacct/second_detail expands to /var/log/freeradius/radacct/second_detail [second_detail] expand: %t -> Tue Oct 25 10:19:36 2011 ++[second_detail] returns ok
... and that part shows an accounting packet written to two different detail file by the "detail" and "second_detail" instance.
Polling for detail file /var/log/freeradius/radacct/second_detail Detail - Renaming /var/log/freeradius/radacct/second_detail -> /var/log/freeradius/radacct/second_detail.work detail_recv: Read packet from /var/log/freeradius/radacct/second_detail.work User-Name = "probador" Acct-Session-Id = "1319530776V34yzo" NAS-IP-Address = 127.0.0.1 NAS-Identifier = "Localhost" NAS-Port = 0 Calling-Station-Id = "1115551212" Acct-Status-Type = Stop Acct-Session-Time = 180 Acct-Delay-Time = 1 Acct-Unique-Session-Id = "7fca33c18994b4b7" Packet-Original-Timestamp = "Oct 25 2011 10:19:36 CEST" Packet-Transmit-Counter = 1 server replicatedRadius {
... and that part shows the rader processing the second_detail file. So everything looks OK. What did you think went wrong, and why? -- Fajar
Yes, I knew that code is to define a reader. Thanks. ;) I think that this function incorrectly (I have some mistake) because when I list /var/log/freeradius/radacct, not appears second_detail file. Now I have included proxy.conf ($INCLUDE proxy.conf) in radiusd.conf and when I launch freeradius -X, I got this output: /etc/freeradius/proxy.conf[114]: Home server radiusB of unexpected type "acct". I think that I can define a home_server as acct type. Maybe this is the problem. Also, I think that this is wrong because my home_server not receives accounting requests. I knew that I had defined the second writer fine, but something it's happening because I think that this file doesn't get to exist. -- View this message in context: http://freeradius.1045715.n5.nabble.com/Why-is-not-writting-in-second-detail... Sent from the FreeRadius - User mailing list archive at Nabble.com.
I have check that I had not defined the pool as acct_pool, for this reason server's type was wrong. -- View this message in context: http://freeradius.1045715.n5.nabble.com/Why-is-not-writting-in-second-detail... Sent from the FreeRadius - User mailing list archive at Nabble.com.
On Tue, Oct 25, 2011 at 4:01 PM, tonimanel <antoniofernandez@fabergames.com> wrote:
Yes, I knew that code is to define a reader. Thanks. ;)
I think that this function incorrectly (I have some mistake) because when I list /var/log/freeradius/radacct, not appears second_detail file.
Did you read the logs you posted? The file was created, and then processed by renaming it to .work, then when processing completes it's deleted and tries to re-read the file again. It's supposed to do that. The only time you'd see the second_detail file in this setup is when the server is writing data faster than the reader can process, or the reader is currently sleeping (about 1 second in your setup) before trying to read it again.
Now I have included proxy.conf ($INCLUDE proxy.conf) in radiusd.conf
wait ... WHAT? Why did you remove it in the first place? The default configuration only needs minimum change to work. Do NOT change what you don't understand. I HIGHLY suggest you redo your setup from fresh install. ONLY modify what you need, and ONLY if you know what the modification does.
Also, I think that this is wrong because my home_server not receives accounting requests.
Probably because you haven't tell the reader what to do with the packet. In the detail reader virtual server (server radiusB in your example), you'd probably need to force the packets to be proxied to a realm previously defined on proxy.conf. Try something like server radiusB { ... accounting { update control { Proxy-To-Realm := "realm_of_my_second_radius_server.com" } } ... } If you didn't tell the server to proxy it (either by setting the realm based on the suffix or whatever previously on proxy.conf, or force it using Proxy-To-Realm), then just an "ok" in accounting section simply means the packet will be discarded.
I knew that I had defined the second writer fine, but something it's happening because I think that this file doesn't get to exist.
Like I said earlier, the process is very fast so unless your load is very high you'd rarely see the file there. -- Fajar
Thanks for your answer. I hadn't put "update control" inside accounting. Now, accounting packets are write, but with different time in "acctstarttime" and "acctstoptime" fields. This fields should to have the same values (I would like to get this). -- View this message in context: http://freeradius.1045715.n5.nabble.com/Why-is-not-writting-in-second-detail... Sent from the FreeRadius - User mailing list archive at Nabble.com.
I have got the same result writting "update control" inside of preacct. This is proxy configuration, but I don't want a proxy configuration, I would like to get a copy-acct-to-home-server configuration with the same set of information in radacct table. I have configured proxy.conf because in copy-acct-tome-server says that proxy.conf must to have realms, pool and home_server. What is wrong? What I should to do? In the last, I had got the same set of information with radrelay configuration (this is deprecated). Then I got proxy configuration, but copy-acct-to-home-server configuration is being very difficult. :( Regards. -- View this message in context: http://freeradius.1045715.n5.nabble.com/Why-is-not-writting-in-second-detail... Sent from the FreeRadius - User mailing list archive at Nabble.com.
I have got the same result writting "update control" inside of preacct. This is proxy configuration, but I don't want a proxy configuration, I would like to get a copy-acct-to-home-server configuration with the same set of information in radacct table. I have configured proxy.conf because in copy-acct-tome-server says that proxy.conf must to have realms, pool and home_server. What is wrong? What I should to do? In the last, I had got the same set of information with radrelay configuration (this is deprecated). Then I got proxy configuration, but copy-acct-to-home-server configuration is being very difficult. :( Regards. -- View this message in context: http://freeradius.1045715.n5.nabble.com/Why-is-not-writting-in-second-detail... Sent from the FreeRadius - User mailing list archive at Nabble.com.
Don't post the same message twice if you just want a faster response. It's rude. If anything, it'd discourage others from even trying to help you, On Tue, Oct 25, 2011 at 9:47 PM, tonimanel <antoniofernandez@fabergames.com> wrote:
I have got the same result writting "update control" inside of preacct. This is proxy configuration, but I don't want a proxy configuration, I would like to get a copy-acct-to-home-server configuration
Remember how I said multiple times that you REALLY need to understand the basics first? Here's some: - radius accepts a packet, whether from a NAS or by reading a detail file - radius process the packet, possibly by using data from several data source (sql, ldap, files, whatever) - radius can store some or all information from the packet, possibly to many destination (sql, detail file, whatever) - radius can proxy the packet to another radius server - radius sends a response to the client PLEASE take some time to REALLY understand the basics. The combination of the above can be used to create all sorts of configuration, including the simple proxy configuration, robust accounting, and copy-acct-to-home-server. Saying "I don't want a proxy configuration, I would like to get a copy-acct-to-home-server configuration" is simply wrong. It's like saying "I don't want meat, I want a beef burger".
with the same set of information in radacct table.
Did you read Alan's previous response on another thread? There's acct-delay-time, and (depending on the NAS) there's also event-timestamp. There might even be Packet-Original-Timestamp (see the detail file to see all attributes present). You might need to edit the default sql queries, but the information is there to create the same set of information. Hint: What's the value of Event-Timestamp or Packet-Original-Timestamp? What do you get when you substract Acct-Delay-Time from those?
I have configured proxy.conf because in copy-acct-tome-server says that proxy.conf must to have realms, pool and home_server.
I never said you didn't need to configure proxy.conf. What I asked was "Why did you remove it in the first place?"
What is wrong? What I should to do?
You didn't understand the basics. PLEASE take some time to REALLY understand the basics.
In the last, I had got the same set of information with radrelay configuration (this is deprecated). Then I got proxy configuration, but copy-acct-to-home-server configuration is being very difficult. :(
radrelay, copy-acct-to-home-server, (put whatever else you've tried here) is simply some implementation that uses the basic concepts, with slightly different goals, combination, and implementation strategy. Again, PLEASE take some time to REALLY understand the basics. -- Fajar
First, thanks for your answer. I think that I understand the basics but I had a doubt with second_detail file because before appeared when I executed a ls. Now I have clear (I knew that second_detail was removed when was readed, but only if the packets were transmited). I have redone the configurations three times getting forever an insufficient solution, but I have learnt a lot. Now, I'm reading a book about RADIUS to expand my knowledge. Now, I don't have clear why configuring proxy.conf and implementing copy-acct-to-home-server, accounting packets have different times(I know that these are using different timestamp). You have said that this is possible changing sql quieries, is not exist another solution for do that? This is my big doubt and now, my big problem. Thanks for your attention and your answers! I hope your answers again. Regards. -- View this message in context: http://freeradius.1045715.n5.nabble.com/Why-is-not-writting-in-second-detail... Sent from the FreeRadius - User mailing list archive at Nabble.com.
On Wed, Oct 26, 2011 at 3:07 PM, tonimanel <antoniofernandez@fabergames.com> wrote:
Now, I don't have clear why configuring proxy.conf and implementing copy-acct-to-home-server, accounting packets have different times(I know that these are using different timestamp).
That's the way it is.
You have said that this is possible changing sql quieries, is not exist another solution for do that?
Short answer: unless your NAS sends Event-Timestamp, then no. Long answer: When a NAS sends Event-Timestamp, freeradius will use that as packet timestamp. You should get the same timestamp no matter how many tiimes the request is proxied. See https://github.com/alandekok/freeradius-server/commit/1fa94b7 When a NAS does NOT send Event-Timestamp, the only way to guess when the packet was first received is by using the current timestamp and Acct-Delay-Time. Current approach taken by the default sql queries (see sql/mysql/dialup.conf for example) is to record both attributes in different columns. If you don't like this you can change the query. -- Fajar
Hi, I have checked my NAS' packets and I can confirm that sends Event-Timestamp (I have seen it from output of freeradius -X). Now, What have I to do? I have seen that Event-Timestamp has not a good mysql format: "Oct 26 2011 13:03:14 CEST". Any idea? Thanks. -- View this message in context: http://freeradius.1045715.n5.nabble.com/Why-is-not-writting-in-second-detail... Sent from the FreeRadius - User mailing list archive at Nabble.com.
participants (2)
-
Fajar A. Nugraha -
tonimanel