Odd behavior?

J Kephart jkephart at safetynetaccess.com
Fri Mar 13 16:24:05 CET 2015


We're seeing a very odd occurrence on one of our radius servers.  To my
knowledge, it has only happened once (this morning), but it's the first
time it's happened, and we're not entirely sure where to look to find
the cause.

We're running on a CentOS 6.6 system, with FR v2.1.12, which is the
package that is distributed by CentOS/RH.  Each day, the logrotate
routing rotates the radius.log (and compresses it), and then restarts
FR.  This morning, however, the radius log showed that the process
restarted, but that it did absolutely nothing for the next two hours and
13 minutes.

Fri Mar 13 03:27:01 2015 : Info: HUP - loading modules
Fri Mar 13 03:27:01 2015 : Info:  Module: Reloaded module
"attr_filter.access_reject"
Fri Mar 13 03:27:01 2015 : Info:  Module: Reloaded module
"attr_filter.accounting_response"
Fri Mar 13 03:27:01 2015 : Info:  Module: Reloaded module "files"
Fri Mar 13 03:27:01 2015 : Info:  Module: Reloaded module "radutmp"
Fri Mar 13 03:27:01 2015 : Info:  Module: Reloaded module "suffix"
Fri Mar 13 03:27:01 2015 : Info:  Module: Reloaded module "mschap"
Fri Mar 13 03:27:01 2015 : Info:  Module: Reloaded module "pap"
Fri Mar 13 03:27:01 2015 : Info: Loaded virtual server <default>
Fri Mar 13 03:27:01 2015 : Info: Loaded virtual server inner-tunnel
Fri Mar 13 05:40:53 2015 : Info: rlm_sql (sql): Driver rlm_sql_mysql
(module rlm_sql_mysql) loaded and linked
Fri Mar 13 05:40:53 2015 : Info: rlm_sql (sql): Attempting to connect to
radius at xxxxxxxxxxxxxxxxx:3306/radius
Fri Mar 13 05:40:53 2015 : Info: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #0
Fri Mar 13 05:40:53 2015 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #0
Fri Mar 13 05:40:53 2015 : Info: rlm_sql (sql): Connected new DB handle, #0
Fri Mar 13 05:40:53 2015 : Info: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #1
Fri Mar 13 05:40:53 2015 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #1
Fri Mar 13 05:40:53 2015 : Info: rlm_sql (sql): Connected new DB handle, #1
Fri Mar 13 05:40:53 2015 : Info: rlm_sql (sql): Attempting to connect
rlm_sql_mysql #2
Fri Mar 13 05:40:53 2015 : Info: rlm_sql_mysql: Starting connect to
MySQL server for #2
...

Following these entries, normal authentication/accounting messages
resumed, as they had been doing just prior.

Has anyone ever run across this?  Any thoughts on how we might track it
down?

Thanks,

Jim


More information about the Freeradius-Users mailing list