postgres sql accounting....

[Robert Myers]

Anyone seen this?

I'm getting some strange errors from postgres, it's almost as if my 
queries aren't filled in the whole way.

What am I missing?  Is my switch just not returning all of the proper 
accounting info?

-Bob





--- Walking the entire request list ---
Cleaning up request 2 ID 87 with timestamp 43e8bcea
Waking up in 2 seconds...
rad_recv: Access-Request packet from host 192.168.2.160:1045, id=90, 
length=70
        User-Name = "root"
        User-Password = "something"
        NAS-IP-Address = 192.168.2.160
        NAS-Identifier = "HP5304"
        NAS-Port-Type = Virtual
        Service-Type = NAS-Prompt-User
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 5
  modcall[authorize]: module "preprocess" returns ok for request 5
  modcall[authorize]: module "chap" returns noop for request 5
  modcall[authorize]: module "mschap" returns noop for request 5
    rlm_realm: No '@' in User-Name = "root", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 5
  rlm_eap: No EAP-Message, not doing EAP
  modcall[authorize]: module "eap" returns noop for request 5
    users: Matched entry DEFAULT at line 157
  modcall[authorize]: module "files" returns ok for request 5
modcall: group authorize returns ok for request 5
  rad_check_password:  Found Auth-Type System
auth: type "System"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 5
rlm_unix: [root]: invalid password
  modcall[authenticate]: module "unix" returns reject for request 5
modcall: group authenticate returns reject for request 5
auth: Failed to validate the user.
Delaying request 5 for 1 seconds
Finished request 5
Going to the next request
--- Walking the entire request list ---
Waking up in 1 seconds...
--- Walking the entire request list ---
Cleaning up request 3 ID 88 with timestamp 43e8bcec
Waking up in 1 seconds...
--- Walking the entire request list ---
Sending Access-Reject of id 90 to 192.168.2.160:1045
Waking up in 2 seconds...
rad_recv: Accounting-Request packet from host 192.168.2.160:1050, id=91, 
length=99
        Acct-Session-Id = "000700000009"
        Acct-Status-Type = Stop
        Service-Type = NAS-Prompt-User
        Acct-Authentic = Local
        Acct-Delay-Time = 15
        NAS-IP-Address = 192.168.2.160
        NAS-Identifier = "HP5304"
        Calling-Station-Id = "192.168.2.152"
        Acct-Terminate-Cause = User-Request
        Acct-Session-Time = 29
  Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 6
  modcall[preacct]: module "preprocess" returns noop for request 6
rlm_acct_unique: WARNING: Attribute NAS-Port was not found in request, 
unique ID MAY be inconsistent
rlm_acct_unique: WARNING: Attribute User-Name was not found in request, 
unique ID MAY be inconsistent
rlm_acct_unique: Hashing ',Client-IP-Address = 
192.168.2.160,NAS-IP-Address = 192.168.2.160,Acct-Session-Id = 
"000700000009",'
rlm_acct_unique: Acct-Unique-Session-ID = "e8b7a55267489b1f".
  modcall[preacct]: module "acct_unique" returns ok for request 6
    rlm_realm: Proxy reply, or no User-Name.  Ignoring.
  modcall[preacct]: module "suffix" returns noop for request 6
  modcall[preacct]: module "files" returns noop for request 6
modcall: group preacct returns ok for request 6
  Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 6
radius_xlat:  '/var/log/radius/radacct/192.168.2.160/detail-20060207'
rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d 
expands to /var/log/radius/radacct/192.168.2.160/detail-20060207
  modcall[accounting]: module "detail" returns ok for request 6
  modcall[accounting]: module "unix" returns noop for request 6
radius_xlat:  '/var/log/radius/radutmp'
radius_xlat:  ''
  rlm_radutmp: No NAS-Port seen.  Cannot do anything.
  rlm_radumtp: WARNING: checkrad will probably not work!
  modcall[accounting]: module "radutmp" returns noop for request 6
radius_xlat:  ''
radius_xlat:  'UPDATE radacct ??SET AcctStopTime = (now() - 
'15'::interval), ??AcctSessionTime = NULLIF('29', '')::bigint, 
??AcctInputOctets = (('0'::bigint << 32) + '0'::bigint), 
??AcctOutputOctets = (('0'::bigint << 32) + '0'::bigint), 
??AcctTerminateCause = 'User-Request', AcctStopDelay = '15', 
??FramedIPAddress = NULLIF('', '')::inet, ConnectInfo_stop = '' ??WHERE 
AcctSessionId = '000700000009' AND UserName = '' ??AND NASIPAddress = 
'192.168.2.160' AND AcctStopTime IS NULL'
radius_xlat:  '/var/log/radius/sqltrace.sql'
rlm_sql (sql): Reserving sql socket id: 0
rlm_sql_postgresql: query: UPDATE radacct ??SET AcctStopTime = (now() - 
'15'::interval), ??AcctSessionTime = NULLIF('29', '')::bigint, 
??AcctInputOctets = (('0'::bigint << 32) + '0'::bigint), 
??AcctOutputOctets = (('0'::bigint << 32) + '0'::bigint), 
??AcctTerminateCause = 'User-Request', AcctStopDelay = '15', 
??FramedIPAddress = NULLIF('', '')::inet, ConnectInfo_stop = '' ??WHERE 
AcctSessionId = '000700000009' AND UserName = '' ??AND NASIPAddress = 
'192.168.2.160' AND AcctStopTime IS NULL
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: affected rows = 0
radius_xlat:  'INSERT into radacct ??(AcctSessionId, AcctUniqueId, 
UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, 
AcctStopTime, ??AcctSessionTime, AcctAuthentic, ConnectInfo_stop, 
AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, 
??AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress, 
AcctStopDelay) ??values('000700000009', 'e8b7a55267489b1f', '', '', 
'192.168.2.160', ??'', '', (now() -  '15'::interval - '29'::interval), 
??(now() - '15'::interval), NULLIF('29', '')::bigint, ??'Local', '', 
??(('0'::bigint << 32) + '0'::bigint), ??(('0'::bigint << 32) + 
'0'::bigint), '', ??'192.168.2.152', 'User-Request', 'NAS-Prompt-User', 
'', ??NULLIF('', '')::inet, '15')'
radius_xlat:  '/var/log/radius/sqltrace.sql'
rlm_sql_postgresql: query: INSERT into radacct ??(AcctSessionId, 
AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, 
AcctStartTime, AcctStopTime, ??AcctSessionTime, AcctAuthentic, 
ConnectInfo_stop, AcctInputOctets, AcctOutputOctets, CalledStationId, 
CallingStationId, ??AcctTerminateCause, ServiceType, FramedProtocol, 
FramedIPAddress, AcctStopDelay) ??values('000700000009', 
'e8b7a55267489b1f', '', '', '192.168.2.160', ??'', '', (now() -  
'15'::interval - '29'::interval), ??(now() - '15'::interval), 
NULLIF('29', '')::bigint, ??'Local', '', ??(('0'::bigint << 32) + 
'0'::bigint), ??(('0'::bigint << 32) + '0'::bigint), '', 
??'192.168.2.152', 'User-Request', 'NAS-Prompt-User', '', ??NULLIF('', 
'')::inet, '15')
rlm_sql_postgresql: Status: PGRES_FATAL_ERROR
rlm_sql_postgresql: affected rows =
rlm_sql_postgresql: Postgresql check_error: PGRES_FATAL_ERROR, returning 
SQL_DOWN
rlm_sql (sql): Attempting to connect rlm_sql_postgresql #0
rlm_sql (sql): Connected new DB handle, #0
rlm_sql_postgresql: query: INSERT into radacct ??(AcctSessionId, 
AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, 
AcctStartTime, AcctStopTime, ??AcctSessionTime, AcctAuthentic, 
ConnectInfo_stop, AcctInputOctets, AcctOutputOctets, CalledStationId, 
CallingStationId, ??AcctTerminateCause, ServiceType, FramedProtocol, 
FramedIPAddress, AcctStopDelay) ??values('000700000009', 
'e8b7a55267489b1f', '', '', '192.168.2.160', ??'', '', (now() -  
'15'::interval - '29'::interval), ??(now() - '15'::interval), 
NULLIF('29', '')::bigint, ??'Local', '', ??(('0'::bigint << 32) + 
'0'::bigint), ??(('0'::bigint << 32) + '0'::bigint), '', 
??'192.168.2.152', 'User-Request', 'NAS-Prompt-User', '', ??NULLIF('', 
'')::inet, '15')
rlm_sql_postgresql: Status: PGRES_FATAL_ERROR
rlm_sql_postgresql: affected rows =
rlm_sql_postgresql: Postgresql check_error: PGRES_FATAL_ERROR, returning 
SQL_DOWN
rlm_sql (sql): failed after re-connect
rlm_sql (sql): Couldn't insert SQL accounting STOP record - ERROR:  
invalid input syntax for integer: ""
rlm_sql (sql): Released sql socket id: 0
  modcall[accounting]: module "sql" returns fail for request 6
modcall: group accounting returns fail for request 6
Finished request 6
Going to the next request
--- Walking the entire request list ---
Waking up in 1 seconds...
--- Walking the entire request list ---
Cleaning up request 4 ID 89 with timestamp 43e8bcef
Waking up in 2 seconds...
rad_recv: Access-Request packet from host 192.168.2.160:1045, id=92, 
length=70
        User-Name = "root"
        User-Password = "classicnw"
        NAS-IP-Address = 192.168.2.160
        NAS-Identifier = "HP5304"
        NAS-Port-Type = Virtual
        Service-Type = NAS-Prompt-User
  Processing the authorize section of radiusd.conf
modcall: entering group authorize for request 7
  modcall[authorize]: module "preprocess" returns ok for request 7
  modcall[authorize]: module "chap" returns noop for request 7
  modcall[authorize]: module "mschap" returns noop for request 7
    rlm_realm: No '@' in User-Name = "root", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 7
  rlm_eap: No EAP-Message, not doing EAP
  modcall[authorize]: module "eap" returns noop for request 7
    users: Matched entry DEFAULT at line 157
  modcall[authorize]: module "files" returns ok for request 7
modcall: group authorize returns ok for request 7
  rad_check_password:  Found Auth-Type System
auth: type "System"
  Processing the authenticate section of radiusd.conf
modcall: entering group authenticate for request 7
rlm_unix: [root]: invalid password
  modcall[authenticate]: module "unix" returns reject for request 7
modcall: group authenticate returns reject for request 7
auth: Failed to validate the user.
Delaying request 7 for 1 seconds
Finished request 7
Going to the next request
--- Walking the entire request list ---
Cleaning up request 5 ID 90 with timestamp 43e8bcf1
Waking up in 1 seconds...
--- Walking the entire request list ---
Waking up in 1 seconds...
--- Walking the entire request list ---
Sending Access-Reject of id 92 to 192.168.2.160:1045
Waking up in 1 seconds...
--- Walking the entire request list ---
Cleaning up request 6 ID 91 with timestamp 43e8bcf4
Waking up in 3 seconds...
--- Walking the entire request list ---
Cleaning up request 7 ID 92 with timestamp 43e8bcf7
Nothing to do.  Sleeping until we see a request.