Freeradius 2 doesn't start after upgrade to PFS 2.2

Gerard64

I reinstalled i remove the files en folders in /var/log/radacct/ and i removed the /var/log/radacct/ directory all together nothing helped. Last week i installed snort and saw there was an upgrade of the freeradius2 package so i hoped this would solve the problem but sadely no after a reboot freeradius stil does not start and in the log it stil says:

Feb 6 19:13:15 radiusd[74061]: Ready to process requests.
Feb 6 19:13:15 radiusd[71172]: Loaded virtual server <default>Feb 6 19:13:14 php-fpm[45767]: /pkg_edit.php: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'
Feb 6 19:11:54 kernel: em0: promiscuous mode enabled
Feb 6 19:11:51 sshlockout[18525]: sshlockout/webConfigurator v3.0 starting up
Feb 6 19:11:51 login: login on ttyv0 as root
Feb 6 19:11:51 radiusd[97781]: /usr/local/etc/raddb/modules/counter[71]: Instantiation failed for module "daily"
Feb 6 19:11:51 radiusd[97781]: rlm_counter: Failed to open file /var/log/radacct/timecounter/db.daily: No such file or directory
Feb 6 19:11:51 SnortStartup[11750]: Snort START for WAN(60318_em0)…
Feb 6 19:11:50 php-fpm[83475]: /rc.start_packages: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'

after a reboot i have to click the save butting in the freeradius settings then freeradius starts right away. Till the next reboot wen it again doesn't start and again i have to click the save button.</default>

G.D. Wusser Esq.

It is likely that corrupted "/var/log/radacct/timecounter/db.daily" is preventing radiusd from starting.

Delete the file, and you should be able to start the radiusd service.

I have to do it every once in a while on my install. It is not fun that this happens.

Gerard64

Yes there is something going on with this "/var/log/radacct/timecounter/db.daily" and yes freeradius does start wen i delete this file. If i don't delete this file but clink once the save button in freeradius settings without changing anything it starts also right away. But the thing is whatever i do if i remove that file or not the next time i reboot the pfSense box freeradius is stil not starting and i have do it all over again click save or delete that file.

I remember after upgrading PFS from 2.0 to 2.1 i have the same problem back then i got it solved but forgot how i did it. Now after upgrading to 2.2 this happens again but this time i don't get it fixed yet.

I de-installed the freeradius2 package, i upgraded it, i deleted those log files nothing helped.

oke

Same problems. I also followed up all the advices I found in this topic without success.

However, looking in detail at /var/log/radius.log I saw a complaint about allocating port 1812 to address 0.0.0.0 followed by errors. This error seems to happen when a second radius process is started. E.g., when one starts radius in debug mode but forgets to stop the current service. But that is not the case here.

The solution that seems to work at first for me was to go into the edit page of all settings in FreeRADIUS:Interfaces - Authentication, Accounting and Status but without modifying anything and then apply save in each individual edit screen. Don't know afterwards whether Accounting and Status are really required. I also saved again the client confs (via the GUI) since I found on this forum that problems are reported after an upgrade with an open brace "{" in clients.conf https://forum.pfsense.org/index.php?topic=43675.120.

After reboot I saw the radiusd process via ps -fax|grep radiusd. However, this did unfortunately not happen at every reboot. It is still buggy.

myke

Hello everyone,

Same problem with pfsense 2.2.1
Freeradius doesn't want to start.

When i restart the service i've got this message on message log :

kernel: pid 87402 (radiusd), uid 0: exited on signal 11

And when i restart the radiusd in the shell i've got a "segmentation fault".

i think 2.2 doesn't like Freeradius ;)

Best regards.
Myke.

Derelict

Can you run /path/to/radiusd/radiusd -X and see what it bombs out on?

Gerard64

Wahoo I just updated to 2.2.1 just now and after the first reboot everything started the way it should including Freeradius. Tomorrow I'll restart it again to be absolutely sure its not a lucky one time reboot with everything starting correctly.

Gerard64

Today I restarted the PFS box again and sadly problem is still not solved. Freeradius did not start and everything is the same as before.

Derelict

Can you run /path/to/radiusd/radiusd -X and see what it bombs out on?

Gerard64

[2.2.1-RELEASE][root@router.xxxxx.xxx]/: radiusd -X
radiusd: FreeRADIUS Version 2.2.6, for host amd64-portbld-freebsd10.1, built on Jan 28 2015 at 18:26:44
Copyright (C) 1999-2013 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 configuration file /usr/local/etc/raddb/radiusd.conf
including configuration file /usr/local/etc/raddb/clients.conf
including files in directory /usr/local/etc/raddb/modules/
including configuration file /usr/local/etc/raddb/modules/wimax
including configuration file /usr/local/etc/raddb/modules/always
including configuration file /usr/local/etc/raddb/modules/attr_filter
including configuration file /usr/local/etc/raddb/modules/attr_rewrite
including configuration file /usr/local/etc/raddb/modules/cache
including configuration file /usr/local/etc/raddb/modules/chap
including configuration file /usr/local/etc/raddb/modules/checkval
including configuration file /usr/local/etc/raddb/modules/counter
including configuration file /usr/local/etc/raddb/modules/cui
including configuration file /usr/local/etc/raddb/modules/detail
including configuration file /usr/local/etc/raddb/modules/detail.example.com
including configuration file /usr/local/etc/raddb/modules/detail.log
including configuration file /usr/local/etc/raddb/modules/dhcp_sqlippool
including configuration file /usr/local/etc/raddb/sql/mysql/ippool-dhcp.conf
including configuration file /usr/local/etc/raddb/modules/digest
including configuration file /usr/local/etc/raddb/modules/dynamic_clients
including configuration file /usr/local/etc/raddb/modules/echo
including configuration file /usr/local/etc/raddb/modules/etc_group
including configuration file /usr/local/etc/raddb/modules/exec
including configuration file /usr/local/etc/raddb/modules/expiration
including configuration file /usr/local/etc/raddb/modules/expr
including configuration file /usr/local/etc/raddb/modules/files
including configuration file /usr/local/etc/raddb/modules/inner-eap
including configuration file /usr/local/etc/raddb/modules/ippool
including configuration file /usr/local/etc/raddb/modules/krb5
including configuration file /usr/local/etc/raddb/modules/ldap
including configuration file /usr/local/etc/raddb/modules/linelog
including configuration file /usr/local/etc/raddb/modules/otp
including configuration file /usr/local/etc/raddb/modules/logintime
including configuration file /usr/local/etc/raddb/modules/mac2ip
including configuration file /usr/local/etc/raddb/modules/mac2vlan
including configuration file /usr/local/etc/raddb/modules/mschap
including configuration file /usr/local/etc/raddb/modules/ntlm_auth
including configuration file /usr/local/etc/raddb/modules/opendirectory
including configuration file /usr/local/etc/raddb/modules/pam
including configuration file /usr/local/etc/raddb/modules/pap
including configuration file /usr/local/etc/raddb/modules/passwd
including configuration file /usr/local/etc/raddb/modules/perl
including configuration file /usr/local/etc/raddb/modules/policy
including configuration file /usr/local/etc/raddb/modules/preprocess
including configuration file /usr/local/etc/raddb/modules/radrelay
including configuration file /usr/local/etc/raddb/modules/radutmp
including configuration file /usr/local/etc/raddb/modules/realm
including configuration file /usr/local/etc/raddb/modules/redis
including configuration file /usr/local/etc/raddb/modules/rediswho
including configuration file /usr/local/etc/raddb/modules/replicate
including configuration file /usr/local/etc/raddb/modules/smbpasswd
including configuration file /usr/local/etc/raddb/modules/smsotp
including configuration file /usr/local/etc/raddb/modules/soh
including configuration file /usr/local/etc/raddb/modules/sql_log
including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login
including configuration file /usr/local/etc/raddb/modules/sradutmp
including configuration file /usr/local/etc/raddb/modules/unix
including configuration file /usr/local/etc/raddb/modules/acct_unique
including configuration file /usr/local/etc/raddb/modules/motp
including configuration file /usr/local/etc/raddb/modules/datacounter_acct
including configuration file /usr/local/etc/raddb/eap.conf
including configuration file /usr/local/etc/raddb/policy.conf
including files in directory /usr/local/etc/raddb/sites-enabled/
including configuration file /usr/local/etc/raddb/sites-enabled/default
main {
allow_core_dumps = no
}
including dictionary file /usr/local/etc/raddb/dictionary
main {
name = "radiusd"
prefix = "/usr/pbi/freeradius-amd64"
localstatedir = "/var"
sbindir = "/usr/pbi/freeradius-amd64/sbin"
logdir = "/var/log"
run_dir = "/var/run"
radacctdir = "/var/log/radacct"
hostname_lookups = no
max_request_time = 30
cleanup_delay = 5
max_requests = 1024
pidfile = "/var/run/radiusd.pid"
checkrad = "/usr/pbi/freeradius-amd64/sbin/checkrad"
debug_level = 0
proxy_requests = yes
log {
stripped_names = no
auth = no
auth_badpass = no
auth_goodpass = no
msg_badpass = ""
msg_goodpass = ""
}
security {
max_attributes = 200
reject_delay = 1
status_server = no
allow_vulnerable_openssl = no
}
}
radiusd: #### Loading Realms and Home Servers ####
radiusd: #### Loading Clients ####
client AP1 {
ipaddr = 192.168.162.6
require_message_authenticator = no
secret = "3948fh83"
shortname = "AP1"
nastype = "other"
}
client AP2 {
ipaddr = 192.168.162.7
require_message_authenticator = no
secret = "3948fh83"
shortname = "AP2"
nastype = "other"
}
client def-router {
ipaddr = 192.168.162.1
require_message_authenticator = no
secret = "3470892"
shortname = "def-router"
nastype = "other"
}
radiusd: #### Instantiating modules ####
instantiate {
Module: Linked to module rlm_exec
Module: Instantiating module "exec" from file /usr/local/etc/raddb/modules/exec
exec {
wait = no
input_pairs = "request"
shell_escape = yes
timeout = 10
}
Module: Linked to module rlm_expr
Module: Instantiating module "expr" from file /usr/local/etc/raddb/modules/expr
Module: Linked to module rlm_counter
Module: Instantiating module "daily" from file /usr/local/etc/raddb/modules/counter
counter daily {
filename = "/var/log/radacct/timecounter/db.daily"
key = "User-Name"
reset = "daily"
count-attribute = "Acct-Session-Time"
counter-name = "Daily-Session-Time"
check-name = "Max-Daily-Session"
reply-name = "Session-Timeout"
cache-size = 5000
}
rlm_counter: Counter attribute Daily-Session-Time is number 11273
rlm_counter: Current Time: 1426685092 [2015-03-18 14:24:52], Next reset 1426719600 [2015-03-19 00:00:00]
Module: Instantiating module "weekly" from file /usr/local/etc/raddb/modules/counter
counter weekly {
filename = "/var/log/radacct/timecounter/db.weekly"
key = "User-Name"
reset = "weekly"
count-attribute = "Acct-Session-Time"
counter-name = "Weekly-Session-Time"
check-name = "Max-Weekly-Session"
reply-name = "Session-Timeout"
cache-size = 5000
}
rlm_counter: Counter attribute Weekly-Session-Time is number 11275
rlm_counter: Current Time: 1426685092 [2015-03-18 14:24:52], Next reset 1426978800 [2015-03-22 00:00:00]
Module: Instantiating module "monthly" from file /usr/local/etc/raddb/modules/counter
counter monthly {
filename = "/var/log/radacct/timecounter/db.monthly"
key = "User-Name"
reset = "monthly"
count-attribute = "Acct-Session-Time"
counter-name = "Monthly-Session-Time"
check-name = "Max-Monthly-Session"
reply-name = "Session-Timeout"
cache-size = 5000
}
rlm_counter: Counter attribute Monthly-Session-Time is number 11277
rlm_counter: Current Time: 1426685092 [2015-03-18 14:24:52], Next reset 1427842800 [2015-04-01 01:00:00]
Module: Instantiating module "forever" from file /usr/local/etc/raddb/modules/counter
counter forever {
filename = "/var/log/radacct/timecounter/db.forever"
key = "User-Name"
reset = "never"
count-attribute = "Acct-Session-Time"
counter-name = "Forever-Session-Time"
check-name = "Max-Forever-Session"
reply-name = "Session-Timeout"
cache-size = 5000
}
rlm_counter: Counter attribute Forever-Session-Time is number 11279
rlm_counter: Current Time: 1426685092 [2015-03-18 14:24:52], Next reset 0 [2015-03-18 14:00:00]
Module: Linked to module rlm_expiration
Module: Instantiating module "expiration" from file /usr/local/etc/raddb/modules/expiration
expiration {
reply-message = "Password Has Expired "
}
Module: Linked to module rlm_logintime
Module: Instantiating module "logintime" from file /usr/local/etc/raddb/modules/logintime
logintime {
reply-message = "You are calling outside your allowed timespan "
minimum-timeout = 60
}
}
radiusd: #### Loading Virtual Servers ####
server { # from file h▒▒▒
modules {
Module: Creating Auth-Type = MOTP
Module: Creating Auth-Type = digest
Module: Creating Autz-Type = Status-Server
Module: Creating Acct-Type = Status-Server
Module: Creating Post-Auth-Type = REJECT
Module: Checking authenticate {…} for more modules to load
Module: Linked to module rlm_pap
Module: Instantiating module "pap" from file /usr/local/etc/raddb/modules/pap
pap {
encryption_scheme = "auto"
auto_header = no
}
Module: Linked to module rlm_chap
Module: Instantiating module "chap" from file /usr/local/etc/raddb/modules/chap
Module: Linked to module rlm_mschap
Module: Instantiating module "mschap" from file /usr/local/etc/raddb/modules/mschap
mschap {
use_mppe = yes
require_encryption = no
require_strong = no
with_ntdomain_hack = yes
allow_retry = yes
}
Module: Instantiating module "motp" from file /usr/local/etc/raddb/modules/motp
exec motp {
wait = yes
program = " /usr/pbi/freeradius-amd64/local/etc/raddb/scripts/otpverify.sh %{request:User-Name} %{request:User-Password} %{reply:MOTP-Init-Secret} %{reply:MOTP-PIN} %{reply:MOTP-Offset}"
input_pairs = "request"
shell_escape = yes
}
Module: Linked to module rlm_digest
Module: Instantiating module "digest" from file /usr/local/etc/raddb/modules/digest
Module: Linked to module rlm_unix
Module: Instantiating module "unix" from file /usr/local/etc/raddb/modules/unix
unix {
radwtmp = "/var/log/radwtmp"
}
Module: Linked to module rlm_eap
Module: Instantiating module "eap" from file /usr/local/etc/raddb/eap.conf
eap {
default_eap_type = "peap"
timer_expire = 60
ignore_unknown_eap_types = no
cisco_accounting_username_bug = no
max_sessions = 4096
}
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 = "/usr/local/etc/raddb/certs"
pem_file_type = yes
private_key_file = "/usr/local/etc/raddb/certs/server_key.pem"
certificate_file = "/usr/local/etc/raddb/certs/server_cert.pem"
CA_file = "/usr/local/etc/raddb/certs/ca_cert.pem"
private_key_password = "xxxxx"
dh_file = "/usr/local/etc/raddb/certs/dh"
random_file = "/usr/local/etc/raddb/certs/random"
fragment_size = 1024
include_length = yes
check_crl = yes
cipher_list = "DEFAULT"
ecdh_curve = "prime256v1"
cache {
enable = no
lifetime = 24
max_entries = 255
}
verify {
}
ocsp {
enable = no
override_cert_url = no
url = "http://127.0.0.1/ocsp/"
use_nonce = yes
timeout = 0
softfail = no
}
}
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
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
soh = no
}
Module: Linked to sub-module rlm_eap_mschapv2
Module: Instantiating eap-mschapv2
mschapv2 {
with_ntdomain_hack = no
send_error = no
}
Module: Checking authorize {...} for more modules to load
Module: Linked to module rlm_preprocess
Module: Instantiating module "preprocess" from file /usr/local/etc/raddb/modules/preprocess
preprocess {
huntgroups = "/usr/local/etc/raddb/huntgroups"
hints = "/usr/local/etc/raddb/hints"
with_ascend_hack = no
ascend_channels_per_line = 23
with_ntdomain_hack = no
with_specialix_jetstream_hack = no
with_cisco_vsa_hack = no
with_alvarion_vsa_hack = no
}
reading pairlist file /usr/local/etc/raddb/huntgroups
reading pairlist file /usr/local/etc/raddb/hints
Module: Linked to module rlm_realm
Module: Instantiating module "suffix" from file /usr/local/etc/raddb/modules/realm
realm suffix {
format = "suffix"
delimiter = "@"
ignore_default = no
ignore_null = yes
}
Module: Instantiating module "ntdomain" from file /usr/local/etc/raddb/modules/realm
realm ntdomain {
format = "prefix"
delimiter = ""
ignore_default = no
ignore_null = yes
}
Module: Linked to module rlm_files
Module: Instantiating module "files" from file /usr/local/etc/raddb/modules/files
files {
usersfile = "/usr/local/etc/raddb/users"
acctusersfile = "/usr/local/etc/raddb/acct_users"
preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
compat = "no"
}
reading pairlist file /usr/local/etc/raddb/users
reading pairlist file /usr/local/etc/raddb/acct_users
reading pairlist file /usr/local/etc/raddb/preproxy_users
Module: Linked to module rlm_checkval
Module: Instantiating module "checkval" from file /usr/local/etc/raddb/modules/checkval
checkval {
item-name = "Calling-Station-Id"
check-name = "Calling-Station-Id"
data-type = "string"
notfound-reject = no
}
rlm_checkval: Registered name Calling-Station-Id for attribute 31
Module: Checking preacct {...} for more modules to load
Module: Linked to module rlm_acct_unique
Module: Instantiating module "acct_unique" from file /usr/local/etc/raddb/modules/acct_unique
acct_unique {
key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port"
}
Module: Checking accounting {...} for more modules to load
Module: Linked to module rlm_detail
Module: Instantiating module "detail" from file /usr/local/etc/raddb/modules/detail
detail {
detailfile = "/var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d"
header = "%t"
detailperm = 384
dirperm = 493
locking = no
log_packet_header = no
}
Module: Instantiating module "datacounterdaily" from file /usr/local/etc/raddb/modules/datacounter_acct
exec datacounterdaily {
wait = yes
program = "/bin/sh /usr/pbi/freeradius-amd64/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} daily %{request:Acct-Input-Octets} %{request:Acct-Output-Octets}"
input_pairs = "request"
shell_escape = yes
}
Module: Instantiating module "datacounterweekly" from file /usr/local/etc/raddb/modules/datacounter_acct
exec datacounterweekly {
wait = yes
program = "/bin/sh /usr/pbi/freeradius-amd64/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} weekly %{request:Acct-Input-Octets} %{request:Acct-Output-Octets}"
input_pairs = "request"
shell_escape = yes
}
Module: Instantiating module "datacountermonthly" from file /usr/local/etc/raddb/modules/datacounter_acct
exec datacountermonthly {
wait = yes
program = "/bin/sh /usr/pbi/freeradius-amd64/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} monthly %{request:Acct-Input-Octets} %{request:Acct-Output-Octets}"
input_pairs = "request"
shell_escape = yes
}
Module: Instantiating module "datacounterforever" from file /usr/local/etc/raddb/modules/datacounter_acct
exec datacounterforever {
wait = yes
program = "/bin/sh /usr/pbi/freeradius-amd64/local/etc/raddb/scripts/datacounter_acct.sh %{request:User-Name} forever %{request:Acct-Input-Octets} %{request:Acct-Output-Octets}"
input_pairs = "request"
shell_escape = yes
}
Module: Linked to module rlm_radutmp
Module: Instantiating module "radutmp" from file /usr/local/etc/raddb/modules/radutmp
radutmp {
filename = "/var/log/radutmp"
username = "%{User-Name}"
case_sensitive = yes
check_with_nas = yes
perm = 384
callerid = yes
}
Module: Linked to module rlm_attr_filter
Module: Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/modules/attr_filter
attr_filter attr_filter.accounting_response {
attrsfile = "/usr/local/etc/raddb/attrs.accounting_response"
key = "%{User-Name}"
relaxed = no
}
reading pairlist file /usr/local/etc/raddb/attrs.accounting_response
Module: Checking session {...} for more modules to load
Module: Checking pre-proxy {...} for more modules to load
Module: Instantiating module "attr_filter.pre-proxy" from file /usr/local/etc/raddb/modules/attr_filter
attr_filter attr_filter.pre-proxy {
attrsfile = "/usr/local/etc/raddb/attrs.pre-proxy"
key = "%{Realm}"
relaxed = no
}
reading pairlist file /usr/local/etc/raddb/attrs.pre-proxy
Module: Checking post-proxy {...} for more modules to load
Module: Instantiating module "attr_filter.post-proxy" from file /usr/local/etc/raddb/modules/attr_filter
attr_filter attr_filter.post-proxy {
attrsfile = "/usr/local/etc/raddb/attrs"
key = "%{Realm}"
relaxed = no
}
reading pairlist file /usr/local/etc/raddb/attrs
Module: Checking post-auth {...} for more modules to load
Module: Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/modules/attr_filter
attr_filter attr_filter.access_reject {
attrsfile = "/usr/local/etc/raddb/attrs.access_reject"
key = "%{User-Name}"
relaxed = no
}
reading pairlist file /usr/local/etc/raddb/attrs.access_reject
} # modules
} # server
radiusd: #### Opening IP addresses and Ports ####
listen {
type = "auth"
ipaddr = 192.168.162.1
port = 1812
}
listen {
type = "acct"
ipaddr = 192.168.162.1
port = 1813
}
Listening on authentication address 192.168.162.1 port 1812
Listening on accounting address 192.168.162.1 port 1813
Listening on proxy address 192.168.162.1 port 1814
Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.162.7 port 36188, id=198, length=167
Acct-Session-Id = "00000014-00000052"
Acct-Status-Type = Start
Acct-Authentic = RADIUS
User-Name = "xxxxx"
NAS-IP-Address = 192.168.162.7
NAS-Identifier = "24a43cb09d24"
NAS-Port = 0
Called-Station-Id = "2A-A4-3C-B2-9D-24:www.xxxxx.xxx"
Calling-Station-Id = "F4-F1-E1-78-25-72"
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"

Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default

+group preacct {
++[preprocess] = ok
++update request {
expand: %{Acct-Session-Time} ->
… expanding second conditional
expand: %{Acct-Delay-Time} ->
... expanding second conditional
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1426685114 - 0 - 0
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1426685114
++} # update request = noop
[acct_unique] Hashing 'NAS-Port = 0,NAS-Identifier = "24a43cb09d24",NAS-IP-Address = 192.168.162.7,Acct-Session-Id = "00000014-00000052",User-Name = "xxxxxx"'
[acct_unique] Acct-Unique-Session-ID = "4f292197fd2cce30".
++[acct_unique] = ok
[suffix] No '@' in User-Name = "xxxxx", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '' in User-Name = "xxxxx", skipping NULL due to config.
++[ntdomain] = noop
++[files] = noop
+} # group preacct = ok

Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default

+group accounting {
[detail] expand: %{Packet-Src-IP-Address} -> 192.168.162.7
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.162.7/detail-20150318
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.162.7/detail-20150318
[detail] expand: %t -> Wed Mar 18 14:25:14 2015
++[detail] = ok
rlm_counter: We only run on Accounting-Stop packets.
++[daily] = noop
rlm_counter: We only run on Accounting-Stop packets.
++[weekly] = noop
rlm_counter: We only run on Accounting-Stop packets.
++[monthly] = noop
rlm_counter: We only run on Accounting-Stop packets.
++[forever] = noop
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
?? Evaluating (request:Acct-Status-Type == Stop) -> FALSE
?? Evaluating (request:Acct-Status-Type == Interim-Update) -> FALSE
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> FALSE
++[unix] = ok
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
[radutmp] expand: %{User-Name} -> xxxxx
++[radutmp] = ok
++[exec] = noop
[attr_filter.accounting_response] expand: %{User-Name} -> xxxxx
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] = updated
+} # group accounting = updated
Sending Accounting-Response of id 198 to 192.168.162.7 port 36188
Finished request 0.
Cleaning up request 0 ID 198 with timestamp +22
Going to the next request
Ready to process requests.
rad_recv: Accounting-Request packet from host 192.168.162.7 port 36188, id=197, length=209
Acct-Session-Id = "00000014-00000050"
Acct-Status-Type = Stop
Acct-Authentic = RADIUS
User-Name = "xxxxx"
NAS-IP-Address = 192.168.162.7
NAS-Identifier = "24a43cb09d24"
NAS-Port = 0
Called-Station-Id = "2A-A4-3C-B2-9D-24:www.xxxxx.xxx"
Calling-Station-Id = "F4-F1-E1-78-25-72"
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 0Mbps 802.11b"
Acct-Session-Time = 37470
Acct-Input-Packets = 74428
Acct-Output-Packets = 215628
Acct-Input-Octets = 6889347
Acct-Output-Octets = 309713911
Event-Timestamp = "Mar 18 2015 14:24:30 CET"
Acct-Terminate-Cause = User-Request

Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default

+group preacct {
++[preprocess] = ok
++update request {
expand: %{Acct-Session-Time} -> 37470
expand: %{Acct-Delay-Time} ->
… expanding second conditional
expand: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0} -> 1426685114 - 37470 - 0
expand: %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} -> 1426647644
++} # update request = noop
[acct_unique] Hashing 'NAS-Port = 0,NAS-Identifier = "24a43cb09d24",NAS-IP-Address = 192.168.162.7,Acct-Session-Id = "00000014-00000050",User-Name = "xxxxx"'
[acct_unique] Acct-Unique-Session-ID = "dd1874c05f137518".
++[acct_unique] = ok
[suffix] No '@' in User-Name = "xxxxx", skipping NULL due to config.
++[suffix] = noop
[ntdomain] No '' in User-Name = "xxxxx", skipping NULL due to config.
++[ntdomain] = noop
++[files] = noop
+} # group preacct = ok

Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default

+group accounting {
[detail] expand: %{Packet-Src-IP-Address} -> 192.168.162.7
[detail] expand: /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/radacct/192.168.162.7/detail-20150318
[detail] /var/log/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radacct/192.168.162.7/detail-20150318
[detail] expand: %t -> Wed Mar 18 14:25:14 2015
++[detail] = ok
rlm_counter: Packet Unique ID = 'dd1874c05f137518'
rlm_counter: Searching the database for key 'xxxxx'
rlm_counter: Could not find the requested key in the database.
rlm_counter: User=xxxxx, New Counter=860.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[daily] = ok
rlm_counter: Packet Unique ID = 'dd1874c05f137518'
rlm_counter: Searching the database for key 'xxxxx'
rlm_counter: Could not find the requested key in the database.
rlm_counter: User=xxxxx, New Counter=860.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[weekly] = ok
rlm_counter: Packet Unique ID = 'dd1874c05f137518'
rlm_counter: Searching the database for key 'xxxxx'
rlm_counter: Could not find the requested key in the database.
rlm_counter: User=xxxxx, New Counter=860.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[monthly] = ok
rlm_counter: Packet Unique ID = 'dd1874c05f137518'
rlm_counter: Searching the database for key 'xxxxx'
rlm_counter: Could not find the requested key in the database.
rlm_counter: User=xxxxx, New Counter=860.
rlm_counter: Storing new value in database.
rlm_counter: New value stored successfully.
++[forever] = ok
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update))
?? Evaluating (request:Acct-Status-Type == Stop) -> TRUE
?? Skipping (request:Acct-Status-Type == Interim-Update)
++? if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) -> TRUE
++if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) {
[datacounterdaily] expand: %{request:User-Name} -> xxxxx
[datacounterdaily] expand: %{request:Acct-Input-Octets} -> 6889347
[datacounterdaily] expand: %{request:Acct-Output-Octets} -> 309713911
Exec output:
[datacounterdaily] Exec: program returned: 0
+++[datacounterdaily] = ok
[datacounterweekly] expand: %{request:User-Name} -> xxxxx
[datacounterweekly] expand: %{request:Acct-Input-Octets} -> 6889347
[datacounterweekly] expand: %{request:Acct-Output-Octets} -> 309713911
Exec output:
[datacounterweekly] Exec: program returned: 0
+++[datacounterweekly] = ok
[datacountermonthly] expand: %{request:User-Name} -> xxxxx
[datacountermonthly] expand: %{request:Acct-Input-Octets} -> 6889347
[datacountermonthly] expand: %{request:Acct-Output-Octets} -> 309713911
Exec output:
[datacountermonthly] Exec: program returned: 0
+++[datacountermonthly] = ok
[datacounterforever] expand: %{request:User-Name} -> xxxxx
[datacounterforever] expand: %{request:Acct-Input-Octets} -> 6889347
[datacounterforever] expand: %{request:Acct-Output-Octets} -> 309713911
Exec output:
[datacounterforever] Exec: program returned: 0
+++[datacounterforever] = ok
++} # if ((request:Acct-Status-Type == Stop) || (request:Acct-Status-Type == Interim-Update)) = ok
++[unix] = ok
[radutmp] expand: /var/log/radutmp -> /var/log/radutmp
[radutmp] expand: %{User-Name} -> xxxxx
rlm_radutmp: Logout entry for NAS AP2 port 0 has wrong ID
++[radutmp] = ok
++[exec] = noop
[attr_filter.accounting_response] expand: %{User-Name} -> xxxxx
attr_filter: Matched entry DEFAULT at line 12
++[attr_filter.accounting_response] = updated
+} # group accounting = updated
Sending Accounting-Response of id 197 to 192.168.162.7 port 36188
Finished request 1.
Cleaning up request 1 ID 197 with timestamp +22
Going to the next request
Ready to process requests.

Derelict

Going to the next request
Ready to process requests.

Looks like it starts to me.

Gerard64

Yes it did and it does. Wen I (re)start the PFS box Freeradius is not starting. I have to click the save button then it starts right away. I don't have to change any of the settings just click the save button in the settings UI is enough to start Freeradius but it doesn't start after a reboot of the system. Wen I stop freeradius in the PFS web GUI and start it on the ssh command line with radiusd -X it also runs normal.

See https://forum.pfsense.org/index.php?topic=87441.msg480196#msg480196
and https://forum.pfsense.org/index.php?topic=87441.msg487188#msg487188

anzak84

After restart Pfsense 2.2.1 freeradius not starting. If button SAVE on Services:FreeRADIUS: Interfaces or Services:FreeRADIUS: Setting (WebGui) then Starting. How to solve the automatic start? Reinstall/Uninstall does not solve the problem, if there is a reboot.

heper

i think it might be best to create a bugreport for this.
instead of clicking "save' , have you tried restarting the service manually ? (status–>services)

If that works, then you might be able to get it running automatically by temporarily installing the "service watchdog" package and having it monitor the freeradius service.

azzido

Are these full installs or nanobsd installs that are having this issue?

I can reproduce that same error message by deliberately corrupting db.daily file, but once I do that saving FreeRADIUS config pages does not solve the problem. Are you guys deleting the file before saving settings?

G.D. Wusser Esq.

Full symmetric multiprocessing kernel install.
In my case, it is several months between the db.daily corruptions.

I delete the file and do not touch any settings.

azzido

@G.D.:

Full symmetric multiprocessing kernel install.
In my case, it is several months between the db.daily corruptions.

I delete the file and do not touch any settings.

That's interesting, so it does not happen every time you restart FreeRADIUS, but sometimes. Do you use 'Amount of Time' feature under Users tab?
It might help if someone uploaded corrupt db.daily file here.

G.D. Wusser Esq.

That is another user that has it happening on every restart.
In my case it is very long time between corruptions. Though I have very few restarts.

I can tell you that in my case the corrupted db.daily is smaller than a good one.

Corrupted: 16 KiB
Good: 64 KiB

I do not use the "Amount of Time" feature.

azzido

All counter files on my system are 128 KiB. Can you upload your good file, I will compare the two. I have been running FreeRADIUS package since 2.0 RC days and never experienced this issue.

Ivart

With me the problem is mysql56, freeradius2 can´t start after boot but works ok manually starting service after boot.


radiusd[84593]: rlm_sql_mysql: Couldn't connect socket to MySQL server radius@localhost:radius

I´m looking for for a way to delay freeradius2 service to start, I think in this way mysql will be ready for new connections before freeradius starts.