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.
participants (1)
-
Robert Myers