3.0.0 'Null value in first column' in unixodbc xlat
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
participants (1)
-
Michael Rigoni