Freeradius 2 doesn't start after upgrade to PFS 2.2
-
[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 = okExecuting 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-RequestExecuting 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 = okExecuting 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. -
Going to the next request
Ready to process requests.Looks like it starts to me.
-
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 -
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.
-
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.
-
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?
-
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.
-
@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. -
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 KiBI do not use the "Amount of Time" feature.
-
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.
-
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:radiusI´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.
-
New version of FreeRADIUS package 1.6.11 fixes the issue of multiple radiusd instances being launched (see: https://redmine.pfsense.org/issues/4337). It is a long shot that that will resolve your problem, but please upgrade and report back. You do need to remove/install package rather than reinstall for the changes to appear on your system. If the update is installed correctly you should see below lines in /usr/local/etc/rc.d/radiusd.sh
... rc_start() { SERVICENAME="radiusd" LOCKFILE="/tmp/${SERVICENAME}_start.lock" PIDFILE="/var/run/${SERVICENAME}.pid" ... -
FreeRadius 2.2.6_3 pkg v1.6.11 Pfsense 2.2.1. remove/install package. The problem is not solved. How to remove a second copy of the program (The FreeRADIUS daemon)? After removal pkg it remains in line "service"
Log:
rlm_counter: Failed to open file /var/log/radacct/timecounter/db.daily: No such file or directory
radiusd[88428]: /usr/local/etc/raddb/modules/counter[71]: Instantiation failed for module "daily"/usr/local/etc/rc.d/radiusd.sh –>
....
rc_start() {
SERVICENAME="radiusd"
LOCKFILE="/tmp/${SERVICENAME}_start.lock"
PIDFILE="/var/run/${SERVICENAME}.pid"
....
-
Removing the package does not remove "/var/log/radacct/timecounter/db.daily" so delete the file manually and try to start FreeRADIUS.
-
Here also installed the update and rebooted and after that powered off the box and restarted but in both restarts the problem is not solved.
-
Can't reproduce this issue, so unless you guys can post additional info that might help in identifying this problem, this is not going get solved.
As a work around you can probably modify startup script '/usr/local/etc/rc.d/radiusd.sh' to remove corrupt file before every start.
-
Dears,
The problem appeared only when I do restore a full backup & the box reboot & re-installing the installed packages…I have tried all work around here with no luck !
in the console it's sayingStarting package freeradius2...done. Starting /usr/local/etc/rc.d/radius.sh...done.but the service is not started & in the log I can find this:
Apr 20 02:58:32 php-fpm[245]: /rc.start_packages: Restarting/Starting all packages. Apr 20 02:58:32 php-fpm[245]: /rc.start_packages: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Apr 20 02:58:32 php-fpm[245]: /rc.start_packages: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Apr 20 02:58:32 php-fpm[245]: /rc.start_packages: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Apr 20 02:58:32 php-fpm[245]: /rc.start_packages: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Apr 20 02:58:32 php-fpm[245]: /rc.start_packages: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Apr 20 02:58:32 php-fpm[245]: /rc.start_packages: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?' Apr 20 02:58:32 php-fpm[245]: /rc.start_packages: The command '/usr/local/etc/rc.d/radiusd.sh stop' returned exit code '1', the output was 'radiusd not running?'Seems like the box try to stop the service instead of starting it !!!
-
I 've same problem and I can't resolve it :-\ :(
-
I have a fresh pfsense install… with only freeradius & got the error only when restoring the all backup file & the system reboot & reinstalling the packages again...
SOLVED after installing any other package (i.e. squid3 or dansguardian or any other),
if I remove those packages… the problem retains !!! it must have another package installed to start automatically :D :D
-
For my system with regular install (not NanoBSD) and memory file system for /tmp and /var I found a workaround that worked for me in https://forum.pfsense.org/index.php?topic=92636.0.
Still I believe that the problem described is a bug in pfsense/freeradius, which in my case was first introduced when upgrading from 2.2 to 2.2.1 (occasionally no service start at (re)boot). It became even worse (never start at (re)boot) when upgrading to 2.2.2. Note that the in the original clean install of 2.2 freeradius worked flawlessly.
