Hi,
I am having trouble connecting users from nas cisco. The radius accepts the
user's request, but shortly after disconnecting.
Could someone help me with this problem?
Thanks.
Log radius:
(1) Received Access-Request Id 231 from 177.38.112.2:62270 to
177.38.112.4:1812 length 235
(1) Cisco-AVPair = "client-mac-address=4c5e.0cf7.1979"
(1) Acct-Session-Id = "00011afd"
(1) NAS-Port-Id = "0/0/12/500"
(1) Cisco-NAS-Port = "0/0/12/500"
(1) User-Name = "usuariocisco"
(1) Service-Type = Framed-User
(1) User-Password = "tmw"
(1) X-Ascend-Connect-Progress = LCP-Opened
(1) Cisco-AVPair = "connect-progress=LCP Open"
(1) Framed-Protocol = PPP
(1) NAS-Port-Type = Wireless-XGP
(1) Event-Timestamp = "Jan 4 2018 17:24:29 -02"
(1) NAS-Identifier = "PPPoE_ASR9001"
(1) NAS-IP-Address = 177.38.112.2
(1) NAS-IPv6-Address = ::
(1) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
(1) authorize {
(1) policy filter_username {
(1) if (&User-Name) {
(1) if (&User-Name) -> TRUE
(1) if (&User-Name) {
(1) if (&User-Name =~ / /) {
(1) if (&User-Name =~ / /) -> FALSE
(1) if (&User-Name =~ /@[^@]*@/ ) {
(1) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
(1) if (&User-Name =~ /\.\./ ) {
(1) if (&User-Name =~ /\.\./ ) -> FALSE
(1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(1) if (&User-Name =~ /\.$/) {
(1) if (&User-Name =~ /\.$/) -> FALSE
(1) if (&User-Name =~ /(a)\./) {
(1) if (&User-Name =~ /(a)\./) -> FALSE
(1) } # if (&User-Name) = notfound
(1) } # policy filter_username = notfound
(1) [preprocess] = ok
(1) [chap] = noop
(1) [mschap] = noop
(1) eap: No EAP-Message, not doing EAP
(1) [eap] = noop
(1) sql: EXPAND %{User-Name}
(1) sql: --> usuariocisco
(1) sql: SQL-User-Name set to 'usuariocisco'
rlm_sql (sql): Reserved connection (2)
(1) sql: EXPAND SELECT id, UserName, Attribute, Value, Op FROM radcheck
WHERE Username = '%{SQL-User-Name}' ORDER BY id
(1) sql: --> SELECT id, UserName, Attribute, Value, Op FROM radcheck
WHERE Username = 'usuariocisco' ORDER BY id
(1) sql: Executing select query: SELECT id, UserName, Attribute, Value, Op
FROM radcheck WHERE Username = 'usuariocisco' ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 2 , fields = 5
(1) sql: User found in radcheck table
(1) sql: Conditional check items matched, merging assignment check items
(1) sql: Cleartext-Password := "tmw"
(1) sql: Pool-Name := "PoolCisco"
(1) sql: EXPAND SELECT id, UserName, Attribute, Value, Op FROM radreply
WHERE Username = '%{SQL-User-Name}' ORDER BY id
(1) sql: --> SELECT id, UserName, Attribute, Value, Op FROM radreply
WHERE Username = 'usuariocisco' ORDER BY id
(1) sql: Executing select query: SELECT id, UserName, Attribute, Value, Op
FROM radreply WHERE Username = 'usuariocisco' ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 0 , fields = 5
(1) sql: EXPAND SELECT GroupName FROM radusergroup WHERE
UserName='%{SQL-User-Name}' ORDER BY priority
(1) sql: --> SELECT GroupName FROM radusergroup WHERE
UserName='usuariocisco' ORDER BY priority
(1) sql: Executing select query: SELECT GroupName FROM radusergroup WHERE
UserName='usuariocisco' ORDER BY priority
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 1 , fields = 1
(1) sql: User found in the group table
(1) sql: EXPAND SELECT id, GroupName, Attribute, Value, op FROM
radgroupcheck WHERE GroupName = '%{SQL-Group}' ORDER BY id
(1) sql: --> SELECT id, GroupName, Attribute, Value, op FROM
radgroupcheck WHERE GroupName = 'CC' ORDER BY id
(1) sql: Executing select query: SELECT id, GroupName, Attribute, Value, op
FROM radgroupcheck WHERE GroupName = 'CC' ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 0 , fields = 5
(1) sql: Group "CC": Conditional check items matched
(1) sql: Group "CC": Merging assignment check items
(1) sql: EXPAND SELECT id, GroupName, Attribute, Value, op FROM
radgroupreply WHERE GroupName = '%{SQL-Group}' ORDER BY id
(1) sql: --> SELECT id, GroupName, Attribute, Value, op FROM
radgroupreply WHERE GroupName = 'CC' ORDER BY id
(1) sql: Executing select query: SELECT id, GroupName, Attribute, Value, op
FROM radgroupreply WHERE GroupName = 'CC' ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 2 , fields = 5
(1) sql: Group "CC": Merging reply items
(1) sql: Service-Type = Framed-User
(1) sql: Framed-Protocol = PPP
rlm_sql (sql): Released connection (2)
Need 4 more connections to reach 10 spares
rlm_sql (sql): Opening additional connection (6), 1 of 26 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 11982
(1) [sql] = ok
(1) [expiration] = noop
(1) [logintime] = noop
(1) [pap] = updated
(1) } # authorize = updated
(1) Found Auth-Type = PAP
(1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(1) Auth-Type PAP {
(1) pap: Login attempt with password
(1) pap: Comparing with "known good" Cleartext-Password
(1) pap: User authenticated successfully
(1) [pap] = ok
(1) } # Auth-Type PAP = ok
(1) # Executing section post-auth from file
/usr/local/etc/raddb/sites-enabled/default
(1) post-auth {
(1) update {
(1) No attributes updated
(1) } # update = noop
(1) sql: EXPAND .query
(1) sql: --> .query
(1) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (3)
(1) sql: EXPAND %{User-Name}
(1) sql: --> usuariocisco
(1) sql: SQL-User-Name set to 'usuariocisco'
(1) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate)
VALUES('%{User-Name}', '%{%{User-Password}:-Chap-Password}',
'%{reply:Packet-Type}', NOW())
(1) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate)
VALUES('usuariocisco', 'tmw', 'Access-Accept', NOW())
(1) sql: Executing query: INSERT INTO radpostauth (username, pass, reply,
authdate) VALUES('usuariocisco', 'tmw', 'Access-Accept', NOW())
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
(1) sql: SQL query returned: success
(1) sql: 1 record(s) updated
rlm_sql (sql): Released connection (3)
(1) [sql] = ok
rlm_sql (sql): Reserved connection (4)
(1) sqlippool: EXPAND %{User-Name}
(1) sqlippool: --> usuariocisco
(1) sqlippool: SQL-User-Name set to 'usuariocisco'
(1) sqlippool: EXPAND START TRANSACTION
(1) sqlippool: --> START TRANSACTION
(1) sqlippool: Executing query: START TRANSACTION
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 0
(1) 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}'
(1) sqlippool: --> UPDATE radippool SET nasipaddress = '', pool_key = 0,
callingstationid = '', expiry_time = 'now'::timestamp(0) - '1
second'::interval WHERE nasipaddress = '177.38.112.2' AND pool_key = ''
(1) sqlippool: Executing query: UPDATE radippool SET nasipaddress = '',
pool_key = 0, callingstationid = '', expiry_time = 'now'::timestamp(0) - '1
second'::interval WHERE nasipaddress = '177.38.112.2' AND pool_key = ''
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
(1) sqlippool: EXPAND COMMIT
(1) sqlippool: --> COMMIT
(1) sqlippool: Executing query: COMMIT
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 0
(1) sqlippool: EXPAND START TRANSACTION
(1) sqlippool: --> START TRANSACTION
(1) sqlippool: Executing query: START TRANSACTION
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 0
(1) 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
(1) sqlippool: --> SELECT framedipaddress FROM radippool WHERE pool_name
= 'PoolCisco' AND expiry_time < 'now'::timestamp(0) ORDER BY RANDOM() LIMIT
1 FOR UPDATE
(1) sqlippool: Executing select query: SELECT framedipaddress FROM
radippool WHERE pool_name = 'PoolCisco' 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
(1) sqlippool: Allocated IP 177.38.121.8
(1) 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.121.8'
(1) sqlippool: --> UPDATE radippool SET nasipaddress = '177.38.112.2',
pool_key = '', callingstationid = '', username = 'usuariocisco',
expiry_time = 'now'::timestamp(0) + '3600 second'::interval WHERE
framedipaddress = '177.38.121.8'
(1) sqlippool: Executing query: UPDATE radippool SET nasipaddress =
'177.38.112.2', pool_key = '', callingstationid = '', username =
'usuariocisco', expiry_time = 'now'::timestamp(0) + '3600 second'::interval
WHERE framedipaddress = '177.38.121.8'
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
(1) sqlippool: EXPAND COMMIT
(1) sqlippool: --> COMMIT
(1) sqlippool: Executing query: COMMIT
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 0
rlm_sql (sql): Released connection (4)
(1) 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})
(1) sqlippool: --> Allocated IP: 177.38.121.8 from PoolCisco (did cli
port user usuariocisco)
(1) [sqlippool] = ok
(1) policy remove_reply_message_if_eap {
(1) if (&reply:EAP-Message && &reply:Reply-Message) {
(1) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
(1) else {
(1) [noop] = noop
(1) } # else = noop
(1) } # policy remove_reply_message_if_eap = noop
(1) } # post-auth = ok
(1) Sent Access-Accept Id 231 from 177.38.112.4:1812 to 177.38.112.2:62270
length 0
(1) Service-Type = Framed-User
(1) Framed-Protocol = PPP
(1) Framed-IP-Address = 177.38.121.8
(1) Finished request
Waking up in 3.4 seconds.
Waking up in 7.5 seconds.
Waking up in 5.9 seconds.
Waking up in 0.9 seconds.
(0) Cleaning up request packet ID 230 with timestamp +0
Waking up in 20.5 seconds.
