(0) Received Access-Request Id 178 from 172.23.4.2:16505 to 177.38.112.4:1812 length 236 (0) Cisco-AVPair = "client-mac-address=4c5e.0cf7.1979" (0) Acct-Session-Id = "0000391b" (0) NAS-Port-Id = "0/0/12/500" (0) Cisco-NAS-Port = "0/0/12/500" (0) User-Name = "tiago@tmw.net" (0) Service-Type = Framed-User (0) User-Password = "tmw" (0) X-Ascend-Connect-Progress = LCP-Opened (0) Cisco-AVPair = "connect-progress=LCP Open" (0) Framed-Protocol = PPP (0) NAS-Port-Type = Wireless-XGP (0) Event-Timestamp = "Nov 16 2017 18:05:41 -02" (0) NAS-Identifier = "PPPoE_ASR9001" (0) NAS-IP-Address = 172.23.4.2 (0) NAS-IPv6-Address = :: (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (0) authorize { (0) policy filter_username { (0) if (&User-Name) { (0) if (&User-Name) -> TRUE (0) if (&User-Name) { (0) if (&User-Name =~ / /) { (0) if (&User-Name =~ / /) -> FALSE (0) if (&User-Name =~ /@[^@]*@/ ) { (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (0) if (&User-Name =~ /\.\./ ) { (0) if (&User-Name =~ /\.\./ ) -> FALSE (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { (0) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE (0) if (&User-Name =~ /\.$/) { (0) if (&User-Name =~ /\.$/) -> FALSE (0) if (&User-Name =~ /@\./) { (0) if (&User-Name =~ /@\./) -> FALSE (0) } # if (&User-Name) = notfound (0) } # policy filter_username = notfound (0) [preprocess] = ok (0) [chap] = noop (0) [mschap] = noop (0) [digest] = noop (0) suffix: Checking for suffix after "@" (0) suffix: Looking up realm "tmw.net" for User-Name = "tiago@tmw.net" (0) suffix: No such realm "tmw.net" (0) [suffix] = noop (0) eap: No EAP-Message, not doing EAP (0) [eap] = noop (0) sql: EXPAND %{User-Name} (0) sql: --> tiago@tmw.net (0) sql: SQL-User-Name set to 'tiago@tmw.net' rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 2043 seconds rlm_sql_postgresql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 2043 seconds rlm_sql_postgresql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 2043 seconds rlm_sql_postgresql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 2043 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_postgresql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 2043 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_postgresql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 2043 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_postgresql: Socket destructor called, closing socket rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare" rlm_sql (sql): Opening additional connection (6), 1 of 32 pending slots used rlm_sql_postgresql: Connecting using parameters: dbname='radius' host='10.65.65.253' port=5432 user='radius' password='bdR4dius' Connected to database 'radius' on '10.65.65.253' server version 100000, protocol version 3, backend PID 8814 rlm_sql (sql): Reserved connection (6) (0) sql: EXPAND SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id (0) sql: --> SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = 'tiago@tmw.net' ORDER BY id (0) sql: Executing select query: SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = 'tiago@tmw.net' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 2 , fields = 5 (0) sql: User found in radcheck table (0) sql: Conditional check items matched, merging assignment check items (0) sql: Cleartext-Password := "tmw" (0) sql: Pool-Name := "Fixo" (0) sql: EXPAND SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id (0) sql: --> SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = 'tiago@tmw.net' ORDER BY id (0) sql: Executing select query: SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = 'tiago@tmw.net' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 5 (0) sql: EXPAND SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority (0) sql: --> SELECT GroupName FROM radusergroup WHERE UserName=' tiago@tmw.net' ORDER BY priority (0) sql: Executing select query: SELECT GroupName FROM radusergroup WHERE UserName='tiago@tmw.net' ORDER BY priority rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 1 (0) sql: User not found in any groups rlm_sql (sql): Released connection (6) Need 2 more connections to reach min connections (3) rlm_sql (sql): Opening additional connection (7), 1 of 31 pending slots used rlm_sql_postgresql: Connecting using parameters: dbname='radius' host='10.65.65.253' port=5432 user='radius' password='bdR4dius' Connected to database 'radius' on '10.65.65.253' server version 100000, protocol version 3, backend PID 8815 (0) [sql] = ok (0) [expiration] = noop (0) [logintime] = noop (0) [pap] = updated (0) } # authorize = updated (0) Found Auth-Type = PAP (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (0) Auth-Type PAP { (0) pap: Login attempt with password (0) pap: Comparing with "known good" Cleartext-Password (0) pap: User authenticated successfully (0) [pap] = ok (0) } # Auth-Type PAP = ok (0) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default (0) post-auth { (0) update { (0) No attributes updated (0) } # update = noop (0) sql: EXPAND .query (0) sql: --> .query (0) sql: Using query template 'query' rlm_sql (sql): Reserved connection (6) (0) sql: EXPAND %{User-Name} (0) sql: --> tiago@tmw.net (0) sql: SQL-User-Name set to 'tiago@tmw.net' (0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES('%{User-Name}', '%{%{User-Password}:-Chap-Password}', '%{reply:Packet-Type}', NOW()) (0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES('tiago@tmw.net', 'tmw', 'Access-Accept', NOW()) (0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES('tiago@tmw.net', 'tmw', 'Access-Accept', NOW()) rlm_sql_postgresql: Status: PGRES_COMMAND_OK rlm_sql_postgresql: query affected rows = 1 (0) sql: SQL query returned: success (0) sql: 1 record(s) updated rlm_sql (sql): Released connection (6) (0) [sql] = ok rlm_sql (sql): Reserved connection (7) (0) sqlippool: EXPAND %{User-Name} (0) sqlippool: --> tiago@tmw.net (0) sqlippool: SQL-User-Name set to 'tiago@tmw.net' (0) sqlippool: EXPAND START TRANSACTION (0) sqlippool: --> START TRANSACTION (0) sqlippool: Executing query: START TRANSACTION rlm_sql_postgresql: Status: PGRES_COMMAND_OK rlm_sql_postgresql: query affected rows = 0 (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', expiry_time = 'now'::timestamp(0) - '1 second'::interval WHERE nasipaddress = '%{NAS-IP-Address}' AND pool_key = '%{Calling-Station-Id}' (0) sqlippool: --> UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', expiry_time = 'now'::timestamp(0) - '1 second'::interval WHERE nasipaddress = '172.23.4.2' AND pool_key = '' (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', expiry_time = 'now'::timestamp(0) - '1 second'::interval WHERE nasipaddress = '172.23.4.2' AND pool_key = '' rlm_sql_postgresql: Status: PGRES_COMMAND_OK rlm_sql_postgresql: query affected rows = 0 (0) sqlippool: EXPAND COMMIT (0) sqlippool: --> COMMIT (0) sqlippool: Executing query: COMMIT rlm_sql_postgresql: Status: PGRES_COMMAND_OK rlm_sql_postgresql: query affected rows = 0 (0) sqlippool: EXPAND START TRANSACTION (0) sqlippool: --> START TRANSACTION (0) sqlippool: Executing query: START TRANSACTION rlm_sql_postgresql: Status: PGRES_COMMAND_OK rlm_sql_postgresql: query affected rows = 0 (0) sqlippool: EXPAND SELECT framedipaddress FROM radippool WHERE pool_name = '%{control:Pool-Name}' AND expiry_time < 'now'::timestamp(0) ORDER BY RANDOM() LIMIT 1 FOR UPDATE (0) sqlippool: --> SELECT framedipaddress FROM radippool WHERE pool_name = 'Fixo' AND expiry_time < 'now'::timestamp(0) ORDER BY RANDOM() LIMIT 1 FOR UPDATE (0) sqlippool: Executing select query: SELECT framedipaddress FROM radippool WHERE pool_name = 'Fixo' AND expiry_time < 'now'::timestamp(0) ORDER BY RANDOM() LIMIT 1 FOR UPDATE rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 1 , fields = 1 (0) sqlippool: Allocated IP 177.38.114.9 (0) sqlippool: EXPAND UPDATE radippool SET nasipaddress = '%{NAS-IP-Address}', pool_key = '%{Calling-Station-Id}', callingstationid = '%{Calling-Station-Id}', username = '%{SQL-User-Name}', expiry_time = 'now'::timestamp(0) + '3600 second'::interval WHERE framedipaddress = '177.38.114.9' (0) sqlippool: --> UPDATE radippool SET nasipaddress = '172.23.4.2', pool_key = '', callingstationid = '', username = 'tiago@tmw.net', expiry_time = 'now'::timestamp(0) + '3600 second'::interval WHERE framedipaddress = '177.38.114.9' (0) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '172.23.4.2', pool_key = '', callingstationid = '', username = ' tiago@tmw.net', expiry_time = 'now'::timestamp(0) + '3600 second'::interval WHERE framedipaddress = '177.38.114.9' rlm_sql_postgresql: Status: PGRES_COMMAND_OK rlm_sql_postgresql: query affected rows = 1 (0) sqlippool: EXPAND COMMIT (0) sqlippool: --> COMMIT (0) sqlippool: Executing query: COMMIT rlm_sql_postgresql: Status: PGRES_COMMAND_OK rlm_sql_postgresql: query affected rows = 0 rlm_sql (sql): Released connection (7) (0) sqlippool: EXPAND Allocated IP: %{reply:Framed-IP-Address} from %{control:Pool-Name} (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name}) (0) sqlippool: --> Allocated IP: 177.38.114.9 from Fixo (did cli port user tiago@tmw.net) (0) [sqlippool] = ok (0) [exec] = noop (0) policy remove_reply_message_if_eap { (0) if (&reply:EAP-Message && &reply:Reply-Message) { (0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (0) else { (0) [noop] = noop (0) } # else = noop (0) } # policy remove_reply_message_if_eap = noop (0) } # post-auth = ok (0) Sent Access-Accept Id 178 from 177.38.112.4:1812 to 172.23.4.2:16505 length 0 (0) Framed-IP-Address = 177.38.114.9 (0) Finished request Waking up in 7.9 seconds. (0) Cleaning up request packet ID 178 with timestamp +2043 Ready to process requests 2017-11-16 17:49 GMT-02:00 Alan DeKok <aland@deployingradius.com>:
On Nov 16, 2017, at 2:46 PM, Yahn do Amaral Almeida Pinheiro < yahnaamaralp@gmail.com> wrote:
My Radacct is not working, can anyone help me?
Radius -X:
Post a debug log where it shows the server receiving, and processing, a packet.
Alan DeKok.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/ list/users.html