<html>
  <head>
    <meta http-equiv="content-type" content="text/html; charset=UTF-8">
  </head>
  <body text="#000000" bgcolor="#FFFFFF">
    Hi list,<br>
    <br>
    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...<br>
    It uses UnixODBC to connect to MSSQL db (tried it with posgresql
    odbc driver and does the same).<br>
    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:<br>
    <ul>
      <li>./configure</li>
      <li>make</li>
      <li>make install</li>
      <li>enabled sql module (see attachment)</li>
      <li>added the following lines to sites enabled/default, just after
        'preprocess' in 'authorize' section:</li>
    </ul>
    <p><tt>        update reply {</tt><tt><br>
      </tt><tt>                Tmp-String-0 := "%{sql:SELECT username
        from mytest WHERE csid = '%{Calling-Station-Id}'}"</tt><tt><br>
      </tt><tt>        }<br>
      </tt></p>
    <ul>
      <li>Commented out the '-sql' in authorize section (was making FR
        segfault, certainly because the SQL tables mentionned in
        'queries.conf' did not exist).</li>
    </ul>
    <p>On first request (see also full debug attached), it gets the
      value correctly:<br>
    </p>
    <tt><br>
    </tt><tt>Tue Oct 22 05:39:55 2013 : Debug: rlm_sql (sql): Reserved
      connection (4)</tt><tt><br>
    </tt><tt>Tue Oct 22 05:39:55 2013 : Debug: rlm_sql (sql): Executing
      query: 'SELECT username from mytest WHERE csid = 'FFFFFFFFFFF0''</tt><tt><br>
    </tt><tt>Tue Oct 22 05:39:55 2013 : Debug: (0) sql_xlat finished</tt><tt><br>
    </tt><tt>Tue Oct 22 05:39:55 2013 : Debug: rlm_sql (sql): Released
      connection (4)</tt><tt><br>
    </tt><tt>Tue Oct 22 05:39:55 2013 : Info: rlm_sql (sql): Closing
      connection (0): Too many free connections (5 > 3)</tt><tt><br>
    </tt><tt>Tue Oct 22 05:39:55 2013 : Debug: rlm_sql_unixodbc: Socket
      destructor called, closing socket</tt><tt><br>
    </tt><tt>Tue Oct 22 05:39:55 2013 : Debug: (0)     </tt><tt><b>expand:


        "%{sql:SELECT username from mytest WHERE csid =
        '%{Calling-Station-Id}'}" -> 'test'</b></tt><br>
    <br>
    But one second request, it fails (returns empty string) saying '<tt><b>Null


        value in first column</b></tt>':<br>
    <br>
    <tt>Tue Oct 22 05:41:36 2013 : Debug: rlm_sql (sql): Executing
      query: 'SELECT username from mytest WHERE csid = 'FFFFFFFFFFF0''</tt><tt><br>
    </tt><tt>Tue Oct 22 05:41:36 2013 : Debug: (1) </tt><tt><b>Null
        value in first column</b></tt><tt><br>
    </tt><tt>Tue Oct 22 05:41:36 2013 : Debug: rlm_sql (sql): Released
      connection (4)</tt><tt><br>
    </tt><tt>Tue Oct 22 05:41:36 2013 : Info: rlm_sql (sql): Closing
      connection (1): Too many free connections (4 > 3)</tt><tt><br>
    </tt><tt>Tue Oct 22 05:41:36 2013 : Debug: rlm_sql_unixodbc: Socket
      destructor called, closing socket</tt><tt><br>
    </tt><tt>Tue Oct 22 05:41:36 2013 : Info: rlm_sql (sql): Closing
      connection (3): Hit idle_timeout, was idle for 123 seconds</tt><tt><br>
    </tt><tt>Tue Oct 22 05:41:36 2013 : rlm_sql (sql): You probably need
      to lower "min"</tt><tt><br>
    </tt><tt>Tue Oct 22 05:41:36 2013 : Debug: rlm_sql_unixodbc: Socket
      destructor called, closing socket</tt><tt><br>
    </tt><tt>Tue Oct 22 05:41:36 2013 : Info: rlm_sql (sql): Closing
      connection (2): Hit idle_timeout, was idle for 123 seconds</tt><tt><br>
    </tt><tt>Tue Oct 22 05:41:36 2013 : Debug: rlm_sql_unixodbc: Socket
      destructor called, closing socket</tt><tt><br>
    </tt><tt>Tue Oct 22 05:41:36 2013 : Debug: (1)     expand:</tt><tt><b>
        "%{sql:SELECT username from mytest WHERE csid =
        '%{Calling-Station-Id}'}" -> ''</b></tt><b><br>
    </b><br>
    Sometimes it works with further requests, sometimes not... It seems
    to work when a new connection to DB is made:<br>
    <tt>Tue Oct 22 06:20:44 2013 : Debug: rlm_sql (sql): Released
      connection (5)</tt><tt><br>
    </tt><tt>Tue Oct 22 06:20:44 2013 : Info: rlm_sql (sql): <b>Opening
        additional connection</b> (6)</tt><tt><br>
    </tt><tt>Tue Oct 22 06:20:44 2013 : Debug: (8)     expand:
      "%{sql:SELECT username from mytest WHERE csid =
      '%{Calling-Station-Id}'}" -> 'test'</tt><tt><br>
    </tt><tt>Tue Oct 22 06:20:44 2013 : Debug: (8)         Tmp-String-0
      := "test"</tt><tt><br>
    </tt><br>
    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  :)<br>
    <br>
    Any ideas how to fix this ?<br>
    <br>
    Michael <br>
    <br>
    <br>
    <br>
    <br>
    <br>
    <br>
    <br>
  </body>
</html>