sql and interim update packets

[Andrew D <andrewd@webzone.net.au>]

Hi there,

We're running freeradius 1.1.4 on freebsd 5.5, using unixodbc and 
freetds to talk to mssql.

According to the default mssql file file the _alt queries are only 
supposed to run if there is an error when doing the first sql query.

# accounting_update_query       - query for Accounting update packets
# accounting_update_query_alt   - query for Accounting update packets
#                               (alternate in case first query fails)

However this isn't the case.


        User-Name = "aliencroc"
        NAS-Port-Type = ADSL-DMT
        Attr-103 = 0x45e50bfe
rad_lowerpair:  User-Name now 'aliencroc'
rad_rmspace_pair:  User-Name now 'aliencroc'
  Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 0
  modcall[preacct]: module "preprocess" returns noop for request 0
rlm_acct_unique: Hashing 'NAS-Port = 1851,Client-IP-Address = 
203.132.224.35,NAS-IP-Address = 203.220.236.246,Acct-Session-Id = 
"00152C4F",User-Name = "aliencroc"'
rlm_acct_unique: Acct-Unique-Session-ID = "b577760b95764125".
  modcall[preacct]: module "acct_unique" returns ok for request 0
    rlm_realm: No '@' in User-Name = "aliencroc", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[preacct]: module "suffix" returns noop for request 0
  modcall[preacct]: module "files" returns noop for request 0
modcall: leaving group preacct (returns ok) for request 0
  Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 0
radius_xlat:  '/var/log/radacct/203.132.224.35/detail-20070228'
rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands 
to /var/log/radacct/203.132.224.35/detail-20070228
  modcall[accounting]: module "detail" returns ok for request 0
radius_xlat:  '/var/log/radutmp'
radius_xlat:  'aliencroc'
  modcall[accounting]: module "radutmp" returns ok for request 0
radius_xlat:  'aliencroc'
rlm_sql (sql): sql_set_user escaped user --> 'aliencroc'
radius_xlat:  'UPDATE CallsOnline SET DataIn = '262653',DataOut = 
'354385', LastHit = getdate() WHERE AcctSessionId = '00152C4F' AND 
UserName = 'aliencroc' AND NASIdentifier= '203.220.236.246''
rlm_sql (sql): Reserving sql socket id: 4
radius_xlat:  'INSERT into accounting (LogTime, LogDate, UserName, 
NasIPAddress, NasPortID, ServiceType, FramedProtocol, FramedAddress, 
CallingStation
ID, NasIdentifier,AcctStatusType,  NasPortType, ConnectInfo, 
ConnectInfo2, AcctUniqueID, CalledStationID, Connection_ID) values 
(getdate(),getdate(),'
aliencroc','203.220.236.246','1851','Framed-User', 'PPP', 
'125.168.108.242','sfy211300202027','LNS02-WAYM-ADL.comindico.com.au','Start','ADSL-DMT','15
5520000','155520000','b577760b95764125','','00152C4F') '
rlm_sql (sql): Released sql socket id: 4
  modcall[accounting]: module "sql" returns ok for request 0
modcall: leaving group accounting (returns ok) for request 0
Sending Accounting-Response of id 67 to 203.132.224.35 port 35240
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...


The first update query didn't fail.
Any ideas or would this be a bug?

Cheers
cya
Andrew