IPPool not logging to radius.log on FreeRadius 3.0.12

[Nataniel Klug]

Hello,

I am running FreeRadius 3.0.12 compiled from source on Debian 8.6. The
problem I am facing is that module ippool is not logging allocation,
release, etc, to the syslog daemon. I have this in my log:

Wed Oct 19 14:45:46 2016 : Auth: (0) Login OK: [teste-sql] (from client
CSC-755-rt-01 port 15728697 cli E4:8D:8C:EC:90:A2)
Wed Oct 19 14:45:55 2016 : Auth: (3) Login OK: [teste-sql] (from client
CSC-755-rt-01 port 15728698 cli E4:8D:8C:EC:90:A2)


When I run in debug mode (-Xx), I can see the module ippool sending the log
message, I just can't see to where:

Wed Oct 19 14:54:41 2016 : Debug: (0) sqlippool: EXPAND UPDATE radippool
SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{NAS-Port}',
callingstationid = '%{Calling-Station-Id}', username = '%{User-Name}',
expiry_time = NOW() + INTERVAL 1920 SECOND WHERE framedipaddress =
'192.168.0.4' AND expiry_time IS NULL
Wed Oct 19 14:54:41 2016 : Debug: (0) sqlippool:    --> UPDATE radippool
SET nasipaddress = '187.19.96.40', pool_key = '15728701', callingstationid
= 'E4:8D:8C:EC:90:A2', username = 'teste-sql', expiry_time = NOW() +
INTERVAL 1920 SECOND WHERE framedipaddress = '192.168.0.4' AND expiry_time
IS NULL
Wed Oct 19 14:54:41 2016 : Debug: (0) sqlippool: Executing query: UPDATE
radippool SET nasipaddress = '187.19.96.40', pool_key = '15728701',
callingstationid = 'E4:8D:8C:EC:90:A2', username = 'teste-sql', expiry_time
= NOW() + INTERVAL 1920 SECOND WHERE framedipaddress = '192.168.0.4' AND
expiry_time IS NULL
Wed Oct 19 14:54:41 2016 : Debug: rlm_sql_mysql: Rows matched: 1  Changed:
1  Warnings: 0
Wed Oct 19 14:54:41 2016 : Debug: COMMIT
Wed Oct 19 14:54:41 2016 : Debug: Parsed xlat tree:
Wed Oct 19 14:54:41 2016 : Debug: literal --> COMMIT
Wed Oct 19 14:54:41 2016 : Debug: (0) sqlippool: EXPAND COMMIT
Wed Oct 19 14:54:41 2016 : Debug: (0) sqlippool:    --> COMMIT
Wed Oct 19 14:54:41 2016 : Debug: (0) sqlippool: Executing query: COMMIT
Wed Oct 19 14:54:41 2016 : Debug: rlm_sql (sql): Released connection (3)
Wed Oct 19 14:54:41 2016 : Debug: Allocated IP: %{reply:Framed-IP-Address}
from %{control:Pool-Name} (did %{Called-Station-Id} cli
%{Calling-Station-Id} port %{NAS-Port} user %{User-Name})
Wed Oct 19 14:54:41 2016 : Debug: Parsed xlat tree:
Wed Oct 19 14:54:41 2016 : Debug: literal --> Allocated IP:
Wed Oct 19 14:54:41 2016 : Debug: attribute --> Framed-IP-Address
Wed Oct 19 14:54:41 2016 : Debug: literal -->  from
Wed Oct 19 14:54:41 2016 : Debug: attribute --> Pool-Name
Wed Oct 19 14:54:41 2016 : Debug: literal -->  (did
Wed Oct 19 14:54:41 2016 : Debug: attribute --> Called-Station-Id
Wed Oct 19 14:54:41 2016 : Debug: literal -->  cli
Wed Oct 19 14:54:41 2016 : Debug: attribute --> Calling-Station-Id
Wed Oct 19 14:54:41 2016 : Debug: literal -->  port
Wed Oct 19 14:54:41 2016 : Debug: attribute --> NAS-Port
Wed Oct 19 14:54:41 2016 : Debug: literal -->  user
Wed Oct 19 14:54:41 2016 : Debug: attribute --> User-Name
Wed Oct 19 14:54:41 2016 : Debug: literal --> )
Wed Oct 19 14:54:41 2016 : Debug: (0) sqlippool: EXPAND Allocated IP:
%{reply:Framed-IP-Address} from %{control:Pool-Name} (did
%{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user
%{User-Name})
Wed Oct 19 14:54:41 2016 : Debug: (0) sqlippool:    --> Allocated IP:
192.168.0.4 from main_pool (did CSC-755-rt-01 cli E4:8D:8C:EC:90:A2 port
15728701 user teste-sql)
Wed Oct 19 14:54:41 2016 : Debug: (0)     modsingle[post-auth]: returned
from sqlippool (rlm_sqlippool)
Wed Oct 19 14:54:41 2016 : Debug: (0)     [sqlippool] = ok
Wed Oct 19 14:54:41 2016 : Debug: (0)   } # post-auth = ok
Wed Oct 19 14:54:41 2016 : Auth: (0) Login OK: [teste-sql] (from client
CSC-755-rt-01 port 15728701 cli E4:8D:8C:EC:90:A2)
Wed Oct 19 14:54:41 2016 : Debug: (0) Sent Access-Accept Id 166 from
186.251.148.124:1812 to 187.19.96.40:44668 length 0
Wed Oct 19 14:54:41 2016 : Debug: (0)   Mikrotik-Rate-Limit = "32k"
Wed Oct 19 14:54:41 2016 : Debug: (0)   Framed-IP-Address = 192.168.0.4
Wed Oct 19 14:54:41 2016 : Debug: (0) Finished request


I can't see the reason that sqlippool is not seding the log to syslog:

Allocated IP: 192.168.0.4 from main_pool (did CSC-755-rt-01 cli
E4:8D:8C:EC:90:A2 port 15728701 user teste-sql)


Atenciosamente,

*Nataniel Klug* | nataniel.klug at gmail.com