rlm_sqlippool

Chris Knipe savage at savage.za.org
Sun Aug 27 03:03:30 CEST 2006 

Hmm.

There seems to also be a bug in the code.  If one of the mysql sockets to 
the database goes down, rlm_sqlippool won't reconnect to the database 
handles...  Debug below for 2 auth requests...

mySQL Logs show that the connection attempt does not even come through. 
Debug logs show that the username of the SQL connection string is incorrect. 
The radius server connects as user 'radius', bug debug shows it attempts to 
connect as 0164

And ty BTW Alan, think I'm starting to get the hang on what's going on irt 
the configuration of the module :-)

Regards,
Chris.


rad_recv: Access-Request packet from host 192.168.1.20:1071, id=212, 
length=209
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 91
        NAS-Port-Type = Ethernet
        User-Name = "username at domain.com"
        Calling-Station-Id = "00:0F:EA:61:0F:B3"
        Called-Station-Id = "NAS01"
        NAS-Port-Id = "Server Network"
        MS-CHAP-Domain = "domain.com"
        User-Password = "password"
        NAS-Identifier = "NAS01"
        NAS-IP-Address = 192.168.1.20
        Mikrotik-Realm = "domain.com"
rad_lowerpair:  User-Name now 'username at domain.com'
rad_lowerpair:  User-Password now 'password'
rad_rmspace_pair:  User-Name now 'username at domain.com'
rad_rmspace_pair:  User-Password now 'password'

<SNIP>

rlm_sql (sql): sql_set_user escaped user --> 'username at domain.com'
radius_xlat:  'SQL QUERY'
rlm_sql (sql): Reserving sql socket id: 5
rlm_sql_mysql: MYSQL check_error: 2006, returning SQL_DOWN
rlm_sql (sql): Attempting to connect rlm_sql_mysql #5
rlm_sql_mysql: Starting connect to MySQL server for #5
rlm_sql (sql): Connected new DB handle, #5
radius_xlat:  'SQL QUERY'
radius_xlat:  'SQL QUERY'
radius_xlat:  'SQL QUERY'
rlm_sql (sql): Released sql socket id: 5
  modcall[authorize]: module "sql" returns ok for request 6
modcall: leaving group authorize (returns ok) for request 6

<SNIP>

radius_xlat:  'username at domain.com'
rlm_sql (sql): sql_set_user escaped user --> 'username at domain.com'
radius_xlat:  'SQL QUERY'
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql_mysql: MYSQL check_error: 2006, returning SQL_DOWN
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): Released sql socket id: 4
  modcall[session]: module "sql" returns ok for request 6
modcall: leaving group session (returns ok) for request 6
Login OK: [username at domain.com] (from client NAS01 port 91 cli 
00:0F:EA:61:0F:B3)

<SNIP>

  Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 6
Value Of the Pool-Name is [6d9a0ffb-8330-1029-8ba8-00005e000164] and its 
[36] Chars
rlm_sql (sql): Reserving sql socket id: 6
radius_xlat:  'BEGIN'
rlm_sql_mysql: MYSQL check_error: 2006, returning SQL_DOWN
rlm_sql (sql): Attempting to connect rlm_sql_mysql #6
rlm_sql_mysql: Starting connect to MySQL server for #6
rlm_sql_mysql: Couldn't connect socket to MySQL server 
0164 at mysqldb01.domain.com:UltimateRadius
rlm_sql_mysql: Mysql error 'Can't connect to MySQL server on 
'mysqldb01.domain.com' (60)'
rlm_sql (sql): Failed to connect DB handle #6
rlm_sql (sql): reconnect failed, database down?
sqlippool_command: database query error

<DOES NOT RECONNECT>

radius_xlat:  'SQL QUERY'
rlm_sql_mysql: Socket not connected
rlm_sql (sql): Attempting to connect rlm_sql_mysql #6
rlm_sql_mysql: Starting connect to MySQL server for #6
rlm_sql_mysql: Couldn't connect socket to MySQL server 
0164 at mysqldb01.domain.com:UltimateRadius
rlm_sql_mysql: Mysql error 'Can't connect to MySQL server on 
'mysqldb01.domain.com' (60)'
rlm_sql (sql): Failed to connect DB handle #6
rlm_sql (sql): reconnect failed, database down?
sqlippool_command: database query error

<STILL NOT>

radius_xlat:  'SQL QUERY'
rlm_sql_mysql: Socket not connected
rlm_sql (sql): Attempting to connect rlm_sql_mysql #6
rlm_sql_mysql: Starting connect to MySQL server for #6
rlm_sql_mysql: Couldn't connect socket to MySQL server 
0164 at mysqldb01.domain.com:UltimateRadius
rlm_sql_mysql: Mysql error 'Can't connect to MySQL server on 
'mysqldb01.domain.com' (60)'
rlm_sql (sql): Failed to connect DB handle #6
rlm_sql (sql): reconnect failed, database down?
sqlippool_query1: database query error
rlm_sqlippool: ip=[] len=0
radius_xlat:  'COMMIT'
rlm_sql_mysql: Socket not connected
rlm_sql (sql): Attempting to connect rlm_sql_mysql #6
rlm_sql_mysql: Starting connect to MySQL server for #6
rlm_sql_mysql: Couldn't connect socket to MySQL server 
0164 at mysqldb01.domain.com:UltimateRadius
rlm_sql_mysql: Mysql error 'Can't connect to MySQL server on 
'mysqldb01.domain.com' (60)'
rlm_sql (sql): Failed to connect DB handle #6
rlm_sql (sql): reconnect failed, database down?
sqlippool_command: database query error

<STILL DOWN>

rlm_sqlippool: IP number could not be allocated.
rlm_sql (sql): Released sql socket id: 6
  modcall[post-auth]: module "sqlippool" returns noop for request 6

<SNIP>

Sending Access-Accept of id 212 to 192.168.1.20 port 1071
        Acct-Interim-Interval := 3600
        Class := 0x574c414e
        Framed-Netmask := 255.255.255.255
        Framed-Protocol := PPP
        Framed-Routing := Broadcast-Listen
        MS-Primary-DNS-Server := 36.0.18.198
        MS-Secondary-DNS-Server := 4.0.18.198
        Service-Type := Framed-User
Finished request 6
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 192.168.1.20:1071, id=212, 
length=209
Sending duplicate reply to client NAS01:1071 - ID: 212
Re-sending Access-Accept of id 212 to 192.168.1.20 port 1071
--- Walking the entire request list ---
Cleaning up request 6 ID 212 with timestamp 44f0ebc5
Nothing to do.  Sleeping until we see a request.
rad_recv: Access-Request packet from host 192.168.1.20:1071, id=212, 
length=209
        Service-Type = Framed-User
        Framed-Protocol = PPP
        NAS-Port = 91
        NAS-Port-Type = Ethernet
        User-Name = "username at domain.com"
        Calling-Station-Id = "00:0F:EA:61:0F:B3"
        Called-Station-Id = "NAS01"
        NAS-Port-Id = "Server Network"
        MS-CHAP-Domain = "domain.com"
        User-Password = "password"
        NAS-Identifier = "NAS01"
        NAS-IP-Address = 192.168.1.20
        Mikrotik-Realm = "domain.com"

<SNIP>

radius_xlat:  'username at domain.com'
rlm_sql (sql): sql_set_user escaped user --> 'username at domain.com'
radius_xlat:  'SQL QUERY'
rlm_sql (sql): Reserving sql socket id: 3
rlm_sql_mysql: MYSQL check_error: 2006, returning SQL_DOWN
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

<IMMEDIATELY RECONNECTS>

radius_xlat:  'SQL QUERY'
radius_xlat:  'SQL QUERY'
radius_xlat:  'SQL QUERY'

<SNIP>

radius_xlat:  'username at domain.com'
rlm_sql (sql): sql_set_user escaped user --> 'username at domain.com'
radius_xlat:  'SQL QUERY'
rlm_sql (sql): Reserving sql socket id: 2
rlm_sql_mysql: MYSQL check_error: 2006, returning SQL_DOWN
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

<RECONNECTS>

rlm_sql (sql): Released sql socket id: 2
  modcall[session]: module "sql" returns ok for request 7
modcall: leaving group session (returns ok) for request 7
Login OK: [username at domain.com] (from client NAS01 port 91 cli 
00:0F:EA:61:0F:B3)
  Processing the post-auth section of radiusd.conf
modcall: entering group post-auth for request 7
Value Of the Pool-Name is [6d9a0ffb-8330-1029-8ba8-00005e000164] and its 
[36] Chars
rlm_sql (sql): Reserving sql socket id: 5
radius_xlat:  'BEGIN'
rlm_sql_mysql: MYSQL check_error: 2006, returning SQL_DOWN
rlm_sql (sql): Attempting to connect rlm_sql_mysql #5
rlm_sql_mysql: Starting connect to MySQL server for #5

<FAILS TO RECONNECT>

More information about the Freeradius-Users mailing list