Hi list,
I am trying to update a FreeRADIUS deployment on RHEL5 to version
3.0.0. This configuration used to work with FreeRADIUS 3.0 dev
branch from October 2012...
It uses UnixODBC to connect to MSSQL db (tried it with posgresql
odbc driver and does the same).
To pin down the issue, I have set up a new deployment of FR with
latest v3.0.x branch and did the following set up:
- ./configure
- make
- make install
- enabled sql module (see attachment)
- added the following lines to sites enabled/default, just after
'preprocess' in 'authorize' section:
update reply {
Tmp-String-0 := "%{sql:SELECT username
from mytest WHERE csid = '%{Calling-Station-Id}'}"
}
- Commented out the '-sql' in authorize section (was making FR
segfault, certainly because the SQL tables mentionned in
'queries.conf' did not exist).
On first request (see also full debug attached), it gets the
value correctly:
Tue Oct 22 05:39:55 2013 : Debug: rlm_sql (sql): Reserved
connection (4)
Tue Oct 22 05:39:55 2013 : Debug: rlm_sql (sql): Executing
query: 'SELECT username from mytest WHERE csid = 'FFFFFFFFFFF0''
Tue Oct 22 05:39:55 2013 : Debug: (0) sql_xlat finished
Tue Oct 22 05:39:55 2013 : Debug: rlm_sql (sql): Released
connection (4)
Tue Oct 22 05:39:55 2013 : Info: rlm_sql (sql): Closing
connection (0): Too many free connections (5 > 3)
Tue Oct 22 05:39:55 2013 : Debug: rlm_sql_unixodbc: Socket
destructor called, closing socket
Tue Oct 22 05:39:55 2013 : Debug: (0) expand:
"%{sql:SELECT username from mytest WHERE csid =
'%{Calling-Station-Id}'}" -> 'test'
But one second request, it fails (returns empty string) saying 'Null
value in first column':
Tue Oct 22 05:41:36 2013 : Debug: rlm_sql (sql): Executing
query: 'SELECT username from mytest WHERE csid = 'FFFFFFFFFFF0''
Tue Oct 22 05:41:36 2013 : Debug: (1) Null
value in first column
Tue Oct 22 05:41:36 2013 : Debug: rlm_sql (sql): Released
connection (4)
Tue Oct 22 05:41:36 2013 : Info: rlm_sql (sql): Closing
connection (1): Too many free connections (4 > 3)
Tue Oct 22 05:41:36 2013 : Debug: rlm_sql_unixodbc: Socket
destructor called, closing socket
Tue Oct 22 05:41:36 2013 : Info: rlm_sql (sql): Closing
connection (3): Hit idle_timeout, was idle for 123 seconds
Tue Oct 22 05:41:36 2013 : rlm_sql (sql): You probably need
to lower "min"
Tue Oct 22 05:41:36 2013 : Debug: rlm_sql_unixodbc: Socket
destructor called, closing socket
Tue Oct 22 05:41:36 2013 : Info: rlm_sql (sql): Closing
connection (2): Hit idle_timeout, was idle for 123 seconds
Tue Oct 22 05:41:36 2013 : Debug: rlm_sql_unixodbc: Socket
destructor called, closing socket
Tue Oct 22 05:41:36 2013 : Debug: (1) expand:
"%{sql:SELECT username from mytest WHERE csid =
'%{Calling-Station-Id}'}" -> ''
Sometimes it works with further requests, sometimes not... It seems
to work when a new connection to DB is made:
Tue Oct 22 06:20:44 2013 : Debug: rlm_sql (sql): Released
connection (5)
Tue Oct 22 06:20:44 2013 : Info: rlm_sql (sql): Opening
additional connection (6)
Tue Oct 22 06:20:44 2013 : Debug: (8) expand:
"%{sql:SELECT username from mytest WHERE csid =
'%{Calling-Station-Id}'}" -> 'test'
Tue Oct 22 06:20:44 2013 : Debug: (8) Tmp-String-0
:= "test"
I did mess around a bit with
src/modules/rlm_sql/drivers/rlm_sql_unixodbc/rlm_sql_unixodbc.c to
check the return value of 'SQLExecDirect' line 163. When it works,
it returns 0 and when it fails -2 (invalid handle ?). The rest of
the code is beyond my comprehension :)
Any ideas how to fix this ?
Michael