semulteneius-use with cisco nas

tolik_shavlovsky at mail.ru tolik_shavlovsky at mail.ru
Fri Dec 9 16:32:49 CET 2011


hi, 

i continue configuring simulteneous-use with cisco NAS.
My configs:
mysql> select * from radcheck;
+----+------------------------------+--------------------+----+------------------------------+
| id | username                     | attribute          | op | value                       
|
+----+------------------------------+--------------------+----+------------------------------+
| 11 | user                         | Cleartext-Password | := | user                        
|
|  3 | test at wimax.com               | Cleartext-Password | := | test                        
|
| 15 | KeepAliveUserNameAndPassword | Cleartext-Password | := |
KeepAliveUserNameAndPassword |
|  5 | test1 at wimax.com              | Cleartext-Password | := | test                        
|
| 10 | user                         | Simultaneous-Use   | := | 1                           
|
| 14 | test1 at wimax.com              | Framed-Filter-Id   | := |
SP=data:MSF=data;            |
| 13 | test at wimax.com               | Framed-Filter-Id   | := |
SP=data:MSF=data;            |
+----+------------------------------+--------------------+----+------------------------------+

clients:
client 10.169.33.11/24 {
  #      require_message_authenticator = no
        secret = "12345"
        nastype = "cisco"
        login       = snmp 
        password    = public 
}

snmpget works:
freebsd# snmpget -v2c -c public 10.169.33.11 sysUpTime.0
DISMAN-EVENT-MIB::sysUpTimeInstance = Timeticks: (147940948) 17 days,
2:56:49.48

debug:
rad_recv: Access-Request packet from host 10.169.33.11 port 1645, id=104,
length=159
        User-Name = "user"
        Framed-MTU = 1400
        Called-Station-Id = "0013.1a08.9340"
        Calling-Station-Id = "001b.7770.9159"
        Service-Type = Login-User
        Message-Authenticator = 0x2e82883f159c894bdd80b8ec62351994
        EAP-Message =
0x020b001d19001703010012b37fc2616cb987f684d4f8af1145e855c165
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 13431
        State = 0x526a475d5a615e1a09ba39034fe381ca
        NAS-IP-Address = 10.169.33.11
        NAS-Identifier = "ap"
Thu Dec  8 17:26:25 2011 : Info: (36) # Executing section authorize from
file /usr/local/etc/raddb/sites-enabled/default
Thu Dec  8 17:26:25 2011 : Info: (36)   group authorize {
Thu Dec  8 17:26:25 2011 : Info: (36)  - entering group authorize {...}
Thu Dec  8 17:26:25 2011 : Info: (36)   [preprocess] = ok
Thu Dec  8 17:26:25 2011 : Info: (36)   [chap] = noop
Thu Dec  8 17:26:25 2011 : Info: (36)   [mschap] = noop
Thu Dec  8 17:26:25 2011 : Info: (36)   [digest] = noop
Thu Dec  8 17:26:25 2011 : Info: (36) suffix : No '@' in User-Name = "user",
looking up realm NULL
Thu Dec  8 17:26:25 2011 : Info: (36) suffix : No such realm "NULL"
Thu Dec  8 17:26:25 2011 : Info: (36)   [suffix] = noop
Thu Dec  8 17:26:25 2011 : Info: (36) eap : EAP packet type response id 11
length 29
Thu Dec  8 17:26:25 2011 : Info: (36) eap : Continuing tunnel setup.
Thu Dec  8 17:26:25 2011 : Info: (36)   [eap] = ok
Thu Dec  8 17:26:25 2011 : Info: (36) Found Auth-Type = ?
Thu Dec  8 17:26:25 2011 : Info: (36) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Dec  8 17:26:25 2011 : Info: (36)   group authenticate {
Thu Dec  8 17:26:25 2011 : Info: (36)  - entering group authenticate {...}
Thu Dec  8 17:26:25 2011 : Info: (36) eap : Request found, released from the
list
Thu Dec  8 17:26:25 2011 : Info: (36) eap : EAP/peap
Thu Dec  8 17:26:25 2011 : Info: (36) eap : processing type peap
Thu Dec  8 17:26:25 2011 : Info: (36) peap : processing EAP-TLS
Thu Dec  8 17:26:25 2011 : Info: (36) peap : eaptls_verify returned 7 
Thu Dec  8 17:26:25 2011 : Info: (36) peap : Done initial handshake
Thu Dec  8 17:26:25 2011 : Info: (36) peap : eaptls_process returned 7 
Thu Dec  8 17:26:25 2011 : Info: (36) peap : FR_TLS_OK
Thu Dec  8 17:26:25 2011 : Info: (36) peap : Session established.  Decoding
tunneled attributes.
Thu Dec  8 17:26:25 2011 : Info: (36) peap : Peap state phase2
Thu Dec  8 17:26:25 2011 : Info: (36) peap : EAP type mschapv2
Thu Dec  8 17:26:25 2011 : Info: (36) peap : Got tunneled request
        EAP-Message = 0x020b00061a03
server  {
Thu Dec  8 17:26:25 2011 : Info: (36) peap : Setting User-Name to user
Sending tunneled request
        EAP-Message = 0x020b00061a03
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "user"
        State = 0xcb00ddfeca0bc7c30919b7db84ca14bd
        Framed-MTU = 1400
        Called-Station-Id = "0013.1a08.9340"
        Calling-Station-Id = "001b.7770.9159"
        Service-Type = Login-User
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 13431
        NAS-IP-Address = 10.169.33.11
        NAS-Identifier = "ap"
server inner-tunnel {
Thu Dec  8 17:26:25 2011 : Info: (36) # Executing section authorize from
file /usr/local/etc/raddb/sites-enabled/inner-tunnel
Thu Dec  8 17:26:25 2011 : Info: (36)   group authorize {
Thu Dec  8 17:26:25 2011 : Info: (36)  - entering group authorize {...}
Thu Dec  8 17:26:25 2011 : Info: (36)   [chap] = noop
Thu Dec  8 17:26:25 2011 : Info: (36)   [mschap] = noop
Thu Dec  8 17:26:25 2011 : Info: (36) suffix : No '@' in User-Name = "user",
looking up realm NULL
Thu Dec  8 17:26:25 2011 : Info: (36) suffix : No such realm "NULL"
Thu Dec  8 17:26:25 2011 : Info: (36)   [suffix] = noop
Thu Dec  8 17:26:25 2011 : Info: (36)   update control {
Thu Dec  8 17:26:25 2011 : Info: (36)   } # update control = noop
Thu Dec  8 17:26:25 2011 : Info: (36) eap : EAP packet type response id 11
length 6
Thu Dec  8 17:26:25 2011 : Info: (36) eap : EAP-MSCHAPV2 success, returning
short-circuit ok
Thu Dec  8 17:26:25 2011 : Info: (36)   [eap] = ok
Thu Dec  8 17:26:25 2011 : Info: (36) Found Auth-Type = ?
Thu Dec  8 17:26:25 2011 : Info: (36) # Executing group from file
/usr/local/etc/raddb/sites-enabled/inner-tunnel
Thu Dec  8 17:26:25 2011 : Info: (36)   group authenticate {
Thu Dec  8 17:26:25 2011 : Info: (36)  - entering group authenticate {...}
Thu Dec  8 17:26:25 2011 : Info: (36) eap : Request found, released from the
list
Thu Dec  8 17:26:25 2011 : Info: (36) eap : EAP/mschapv2
Thu Dec  8 17:26:25 2011 : Info: (36) eap : processing type mschapv2
Thu Dec  8 17:26:25 2011 : Info: (36) eap : Freeing handler
Thu Dec  8 17:26:25 2011 : Info: (36)   [eap] = ok
Thu Dec  8 17:26:25 2011 : Auth: (36) Login OK: [user/<via Auth-Type = ?>]
(from client 10.169.33.11/24 port 13431 cli 001b.7770.9159 via TLS tunnel)
Thu Dec  8 17:26:25 2011 : Info: (36) # Executing section post-auth from
file /usr/local/etc/raddb/sites-enabled/inner-tunnel
Thu Dec  8 17:26:25 2011 : Info: (36)   group post-auth {
Thu Dec  8 17:26:25 2011 : Info: (36)  - entering group post-auth {...}
Thu Dec  8 17:26:25 2011 : Info: (36) sql :     expand: %{User-Name} -> user
Thu Dec  8 17:26:25 2011 : Info: (36) sql : sql_set_user escaped user -->
'user'
Thu Dec  8 17:26:25 2011 : Info: (36) sql :     expand: %{User-Password} -> 
Thu Dec  8 17:26:25 2011 : Info: (36) sql :     ... expanding second
conditional
Thu Dec  8 17:26:25 2011 : Info: (36) sql :     expand: %{Chap-Password} -> 
Thu Dec  8 17:26:25 2011 : Info: (36) sql :     expand:         INSERT INTO
radpostauth         (username, pass, reply, authdate)        VALUES (       
'%{SQL-User-Name}',     '%{%{User-Password}:-%{Chap-Password}}',       
'%{reply:Packet-Type}', '%S') ->         INSERT INTO radpostauth        
(username, pass, reply, authdate)       VALUES (         'user',         '',    
'Access-Accept', '2011-12-08 17:26:25')
Thu Dec  8 17:26:25 2011 : Debug: rlm_sql (sql) in sql_postauth: query is      
INSERT INTO radpostauth         (username, pass, reply, authdate)       
VALUES (        'user',         '',     'Access-Accept', '2011-12-08
17:26:25')
Thu Dec  8 17:26:25 2011 : Debug: rlm_sql (sql): Reserved connection (12)
Thu Dec  8 17:26:25 2011 : Debug: rlm_sql (sql): Released connection (12)
Thu Dec  8 17:26:25 2011 : Info: (36)   [sql] = ok
Thu Dec  8 17:26:25 2011 : Info: (36) sql_log : Processing sql_log_postauth
Thu Dec  8 17:26:25 2011 : Info: (36) sql_log :         expand: %{User-Name}
-> user
Thu Dec  8 17:26:25 2011 : Info: (36) sql_log :         expand:
%{%{User-Name}:-DEFAULT} -> user
Thu Dec  8 17:26:25 2011 : Info: (36) sql_log : sql_set_user escaped user
--> 'user'
Thu Dec  8 17:26:25 2011 : Info: (36) sql_log : WARNING: Deprecated
conditional expansion ":-".  See "man unlang" for details
Thu Dec  8 17:26:25 2011 : Info: (36) sql_log :         ... expanding second
conditional
Thu Dec  8 17:26:25 2011 : Info: (36) sql_log :         expand:
Chap-Password -> Chap-Password
Thu Dec  8 17:26:25 2011 : Info: (36) sql_log :         expand: INSERT INTO
radpostauth                          (username, pass, reply, authdate)
VALUES                         ('%{User-Name}',
'%{User-Password:-Chap-Password}',              '%{reply:Packet-Type}',
'%S'); -> INSERT INTO radpostauth                       (username, pass,
reply, authdate) VALUES                         ('user', 'Chap-Password',              
'Access-Accept', '2011-12-08 17:26:25');
Thu Dec  8 17:26:25 2011 : Info: (36) sql_log :         expand:
/usr/local/var/log/radius/radacct/sql-relay ->
/usr/local/var/log/radius/radacct/sql-relay
Thu Dec  8 17:26:25 2011 : Info: (36)   [sql_log] = ok
} # server inner-tunnel
Thu Dec  8 17:26:25 2011 : Info: (36) peap : Got tunneled reply code 2
        MS-MPPE-Encryption-Policy = Encryption-Allowed
        MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed
        MS-MPPE-Send-Key = 0x4b950af2af95357660e7b7cd0d70c4ee
        MS-MPPE-Recv-Key = 0xe041e091013829024563e0c64a2a8b3e
        EAP-Message = 0x030b0004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "user"
Thu Dec  8 17:26:25 2011 : Info: (36) peap : Got tunneled reply RADIUS code
2
        MS-MPPE-Encryption-Policy = Encryption-Allowed
        MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed
        MS-MPPE-Send-Key = 0x4b950af2af95357660e7b7cd0d70c4ee
        MS-MPPE-Recv-Key = 0xe041e091013829024563e0c64a2a8b3e
        EAP-Message = 0x030b0004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "user"
Thu Dec  8 17:26:25 2011 : Info: (36) peap : Tunneled authentication was
successful.
Thu Dec  8 17:26:25 2011 : Info: (36) peap : SUCCESS
Thu Dec  8 17:26:25 2011 : Info: (36) peap : Saving tunneled attributes for
later
Thu Dec  8 17:26:25 2011 : Info: (36)   [eap] = handled
Sending Access-Challenge of id 104 to 10.169.33.11 port 1645
        EAP-Message =
0x010c00261900170301001b6149c2683fad2144473d4eb64a84d8bb311c1da55a06ac23ef2f1c
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x526a475d5b665e1a09ba39034fe381ca
Thu Dec  8 17:26:25 2011 : Info: (36) Finished request 36.
rad_recv: Access-Request packet from host 10.169.33.11 port 1645, id=105,
length=168
        User-Name = "user"
        Framed-MTU = 1400
        Called-Station-Id = "0013.1a08.9340"
        Calling-Station-Id = "001b.7770.9159"
        Service-Type = Login-User
        Message-Authenticator = 0xf57cb17ca4c07354856cdc1443089a6a
        EAP-Message =
0x020c00261900170301001befdfaf794c7809b50b1718d07d1b237ae93b9c5c6c9a330aa0202c
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 13431
        State = 0x526a475d5b665e1a09ba39034fe381ca
        NAS-IP-Address = 10.169.33.11
        NAS-Identifier = "ap"
Thu Dec  8 17:26:25 2011 : Info: (37) # Executing section authorize from
file /usr/local/etc/raddb/sites-enabled/default
Thu Dec  8 17:26:25 2011 : Info: (37)   group authorize {
Thu Dec  8 17:26:25 2011 : Info: (37)  - entering group authorize {...}
Thu Dec  8 17:26:25 2011 : Info: (37)   [preprocess] = ok
Thu Dec  8 17:26:25 2011 : Info: (37)   [chap] = noop
Thu Dec  8 17:26:25 2011 : Info: (37)   [mschap] = noop
Thu Dec  8 17:26:25 2011 : Info: (37)   [digest] = noop
Thu Dec  8 17:26:25 2011 : Info: (37) suffix : No '@' in User-Name = "user",
looking up realm NULL
Thu Dec  8 17:26:25 2011 : Info: (37) suffix : No such realm "NULL"
Thu Dec  8 17:26:25 2011 : Info: (37)   [suffix] = noop
Thu Dec  8 17:26:25 2011 : Info: (37) eap : EAP packet type response id 12
length 38
Thu Dec  8 17:26:25 2011 : Info: (37) eap : Continuing tunnel setup.
Thu Dec  8 17:26:25 2011 : Info: (37)   [eap] = ok
Thu Dec  8 17:26:25 2011 : Info: (37) Found Auth-Type = ?
Thu Dec  8 17:26:25 2011 : Info: (37) # Executing group from file
/usr/local/etc/raddb/sites-enabled/default
Thu Dec  8 17:26:25 2011 : Info: (37)   group authenticate {
Thu Dec  8 17:26:25 2011 : Info: (37)  - entering group authenticate {...}
Thu Dec  8 17:26:25 2011 : Info: (37) eap : Request found, released from the
list
Thu Dec  8 17:26:25 2011 : Info: (37) eap : EAP/peap
Thu Dec  8 17:26:25 2011 : Info: (37) eap : processing type peap
Thu Dec  8 17:26:25 2011 : Info: (37) peap : processing EAP-TLS
Thu Dec  8 17:26:25 2011 : Info: (37) peap : eaptls_verify returned 7 
Thu Dec  8 17:26:25 2011 : Info: (37) peap : Done initial handshake
Thu Dec  8 17:26:25 2011 : Info: (37) peap : eaptls_process returned 7 
Thu Dec  8 17:26:25 2011 : Info: (37) peap : FR_TLS_OK
Thu Dec  8 17:26:25 2011 : Info: (37) peap : Session established.  Decoding
tunneled attributes.
Thu Dec  8 17:26:25 2011 : Info: (37) peap : Peap state send tlv success
Thu Dec  8 17:26:25 2011 : Info: (37) peap : Received EAP-TLV response.
Thu Dec  8 17:26:25 2011 : Info: (37) peap : Success
Thu Dec  8 17:26:25 2011 : Info: (37) peap : Using saved attributes from the
original Access-Accept
        User-Name = "user"
Thu Dec  8 17:26:25 2011 : Info: (37) eap : Freeing handler
Thu Dec  8 17:26:25 2011 : Info: (37)   [eap] = ok
Thu Dec  8 17:26:25 2011 : Auth: (37) Login OK: [user/<via Auth-Type = ?>]
(from client 10.169.33.11/24 port 13431 cli 001b.7770.9159)
Thu Dec  8 17:26:25 2011 : Info: (37) # Executing section post-auth from
file /usr/local/etc/raddb/sites-enabled/default
Thu Dec  8 17:26:25 2011 : Info: (37)   group post-auth {
Thu Dec  8 17:26:25 2011 : Info: (37)  - entering group post-auth {...}
Thu Dec  8 17:26:25 2011 : Info: (37) sql :     expand: %{User-Name} -> user
Thu Dec  8 17:26:25 2011 : Info: (37) sql : sql_set_user escaped user -->
'user'
Thu Dec  8 17:26:25 2011 : Info: (37) sql :     expand: %{User-Password} -> 
Thu Dec  8 17:26:25 2011 : Info: (37) sql :     ... expanding second
conditional
Thu Dec  8 17:26:25 2011 : Info: (37) sql :     expand: %{Chap-Password} -> 
Thu Dec  8 17:26:25 2011 : Info: (37) sql :     expand:         INSERT INTO
radpostauth         (username, pass, reply, authdate)        VALUES (       
'%{SQL-User-Name}',     '%{%{User-Password}:-%{Chap-Password}}',       
'%{reply:Packet-Type}', '%S') ->         INSERT INTO radpostauth        
(username, pass, reply, authdate)       VALUES (         'user',         '',    
'Access-Accept', '2011-12-08 17:26:25')
Thu Dec  8 17:26:25 2011 : Debug: rlm_sql (sql) in sql_postauth: query is      
INSERT INTO radpostauth         (username, pass, reply, authdate)       
VALUES (        'user',         '',     'Access-Accept', '2011-12-08
17:26:25')
Thu Dec  8 17:26:25 2011 : Debug: rlm_sql (sql): Reserved connection (12)
Thu Dec  8 17:26:25 2011 : Debug: rlm_sql (sql): Released connection (12)
Thu Dec  8 17:26:25 2011 : Info: (37)   [sql] = ok
Thu Dec  8 17:26:25 2011 : Info: (37) sql_log : Processing sql_log_postauth
Thu Dec  8 17:26:25 2011 : Info: (37) sql_log :         expand: %{User-Name}
-> user
Thu Dec  8 17:26:25 2011 : Info: (37) sql_log :         expand:
%{%{User-Name}:-DEFAULT} -> user
Thu Dec  8 17:26:25 2011 : Info: (37) sql_log : sql_set_user escaped user
--> 'user'
Thu Dec  8 17:26:25 2011 : Info: (37) sql_log : WARNING: Deprecated
conditional expansion ":-".  See "man unlang" for details
Thu Dec  8 17:26:25 2011 : Info: (37) sql_log :         ... expanding second
conditional
Thu Dec  8 17:26:25 2011 : Info: (37) sql_log :         expand:
Chap-Password -> Chap-Password
Thu Dec  8 17:26:25 2011 : Info: (37) sql_log :         expand: INSERT INTO
radpostauth                          (username, pass, reply, authdate)
VALUES                         ('%{User-Name}',
'%{User-Password:-Chap-Password}',              '%{reply:Packet-Type}',
'%S'); -> INSERT INTO radpostauth                       (username, pass,
reply, authdate) VALUES                         ('user', 'Chap-Password',              
'Access-Accept', '2011-12-08 17:26:25');
Thu Dec  8 17:26:25 2011 : Info: (37) sql_log :         expand:
/usr/local/var/log/radius/radacct/sql-relay ->
/usr/local/var/log/radius/radacct/sql-relay
Thu Dec  8 17:26:25 2011 : Info: (37)   [sql_log] = ok
Thu Dec  8 17:26:25 2011 : Info: (37)   [exec] = noop
Thu Dec  8 17:26:25 2011 : Info: (37)    policy remove_reply_message_if_eap
{
Thu Dec  8 17:26:25 2011 : Info: (37)   - entering policy
remove_reply_message_if_eap {...}
Thu Dec  8 17:26:25 2011 : Info: (37)    ? if (reply:EAP-Message &&
reply:Reply-Message)
Thu Dec  8 17:26:25 2011 : Info: (37) ? Evaluating (reply:EAP-Message ) ->
TRUE
Thu Dec  8 17:26:25 2011 : Info: (37) ? Evaluating (reply:Reply-Message) ->
FALSE
Thu Dec  8 17:26:25 2011 : Info: (37)    ? if (reply:EAP-Message &&
reply:Reply-Message) -> FALSE
Thu Dec  8 17:26:25 2011 : Info: (37)     else else {
Thu Dec  8 17:26:25 2011 : Info: (37)    - entering else else {...}
Thu Dec  8 17:26:25 2011 : Info: (37)     [noop] = noop
Thu Dec  8 17:26:25 2011 : Info: (37)    - else else returns noop
Thu Dec  8 17:26:25 2011 : Info: (37)   - policy remove_reply_message_if_eap
returns noop
Sending Access-Accept of id 105 to 10.169.33.11 port 1645
        User-Name = "user"
        MS-MPPE-Recv-Key =
0xb6ad8feb9e726faf3476818bb97ba4617babe493ae3317f8f51d5fe7560d676b
        MS-MPPE-Send-Key =
0x1b7714f349209231ebf5846bdb4b41398434d9e013c6ea05b162b9a8220eef32
        EAP-Message = 0x030c0004
        Message-Authenticator = 0x00000000000000000000000000000000
Thu Dec  8 17:26:25 2011 : Info: (37) Finished request 37.
rad_recv: Accounting-Request packet from host 10.169.33.11 port 1646,
id=172, length=224
        Acct-Session-Id = "000033C8"
        Called-Station-Id = "0013.1a08.9340"
        Calling-Station-Id = "001b.7770.9159"
        Cisco-AVPair = "ssid=HAYATT"
        Cisco-AVPair = "vlan-id=55"
        Cisco-AVPair = "nas-location=unspecified"
        User-Name = "user"
        Cisco-AVPair = "connect-progress=Call Up"
        Acct-Authentic = RADIUS
        Acct-Status-Type = Start
        NAS-Port-Type = Wireless-802.11
        Cisco-NAS-Port = "13431"
        NAS-Port = 13431
        Service-Type = Framed-User
        NAS-IP-Address = 10.169.33.11
        Acct-Delay-Time = 0
Thu Dec  8 17:26:25 2011 : Info: (38) # Executing section preacct from file
/usr/local/etc/raddb/sites-enabled/default
Thu Dec  8 17:26:25 2011 : Info: (38)   group preacct {
Thu Dec  8 17:26:25 2011 : Info: (38)  - entering group preacct {...}
Thu Dec  8 17:26:25 2011 : Info: (38)   [preprocess] = ok
Thu Dec  8 17:26:25 2011 : Info: (38)    policy acct_unique {
Thu Dec  8 17:26:25 2011 : Info: (38)   - entering policy acct_unique {...}
Thu Dec  8 17:26:25 2011 : Info: (38)    ? if ("%{string:Class}" =~
/ai:([0-9a-f]{32})/i)
Thu Dec  8 17:26:25 2011 : Info: (38)   expand: %{string:Class} -> 
Thu Dec  8 17:26:25 2011 : Info: (38) ? Evaluating ("%{string:Class}" =~
/ai:([0-9a-f]{32})/i) -> FALSE
Thu Dec  8 17:26:25 2011 : Info: (38)    ? if ("%{string:Class}" =~
/ai:([0-9a-f]{32})/i) -> FALSE
Thu Dec  8 17:26:25 2011 : Info: (38)     else else {
Thu Dec  8 17:26:25 2011 : Info: (38)    - entering else else {...}
Thu Dec  8 17:26:25 2011 : Info: (38)     update request {
Thu Dec  8 17:26:25 2011 : Info: (38)   expand:
%{User-Name}%{Acct-Session-ID}%{NAS-IP-Address}%{NAS-Port-ID:}%{NAS-Port} ->
user000033C810.169.33.1113431
Thu Dec  8 17:26:25 2011 : Info: (38)   expand:
%{md5:%{User-Name}%{Acct-Session-ID}%{NAS-IP-Address}%{NAS-Port-ID:}%{NAS-Port}}
-> df4dee5fb72121b17bd275a4d64782c6
Thu Dec  8 17:26:25 2011 : Info: (38)     } # update request = ok
Thu Dec  8 17:26:25 2011 : Info: (38)    - else else returns ok
Thu Dec  8 17:26:25 2011 : Info: (38)   - policy acct_unique returns ok
Thu Dec  8 17:26:25 2011 : Info: (38) suffix : No '@' in User-Name = "user",
looking up realm NULL
Thu Dec  8 17:26:25 2011 : Info: (38) suffix : No such realm "NULL"
Thu Dec  8 17:26:25 2011 : Info: (38)   [suffix] = noop
Thu Dec  8 17:26:25 2011 : Info: (38)   [files] = noop
Thu Dec  8 17:26:25 2011 : Info: (38) # Executing section accounting from
file /usr/local/etc/raddb/sites-enabled/default
Thu Dec  8 17:26:25 2011 : Info: (38)   group accounting {
Thu Dec  8 17:26:25 2011 : Info: (38)  - entering group accounting {...}
Thu Dec  8 17:26:25 2011 : Info: (38) detail :  expand:
%{Packet-Src-IP-Address} -> 10.169.33.11
Thu Dec  8 17:26:25 2011 : Info: (38) detail :  expand:
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
-> /usr/local/var/log/radius/radacct/10.169.33.11/detail-20111208
Thu Dec  8 17:26:25 2011 : Info: (38) detail :
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/10.169.33.11/detail-20111208
Thu Dec  8 17:26:25 2011 : Info: (38) detail :  expand: %t -> Thu Dec  8
17:26:25 2011
Thu Dec  8 17:26:25 2011 : Info: (38)   [detail] = ok
Thu Dec  8 17:26:25 2011 : Info: (38)   [unix] = ok
Thu Dec  8 17:26:25 2011 : Info: (38) radutmp :         expand:
/usr/local/var/log/radius/radutmp -> /usr/local/var/log/radius/radutmp
Thu Dec  8 17:26:25 2011 : Info: (38) radutmp :         expand: %{User-Name}
-> user
Thu Dec  8 17:26:25 2011 : Info: (38)   [radutmp] = ok
Thu Dec  8 17:26:25 2011 : Info: (38) sql :     expand: %{User-Name} -> user
Thu Dec  8 17:26:25 2011 : Info: (38) sql : sql_set_user escaped user -->
'user'
Thu Dec  8 17:26:25 2011 : Info: (38) sql :     expand: %{Acct-Delay-Time}
-> 0
Thu Dec  8 17:26:25 2011 : Info: (38) sql :     expand:         INSERT INTO
radacct             (acctsessionid, acctuniqueid,            username,              
realm,                  nasipaddress,           nasportid,      nasporttype,            
acctstarttime,          acctstoptime,           acctsessiontime,       
acctauthentic,  connectinfo_start,               connectinfo_stop,      
acctinputoctets,        acctoutputoctets,               calledstationid,        
callingstationid,       acctterminatecause,             servicetype,           
framedprotocol,          framedipaddress,                acctstartdelay,        
acctstopdelay,          xascendsessionsvrkey)    VALUES         
('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',            
'%{SQL-User-Name}',     '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}',         
'%{NAS-Port-Type}', '%S', NULL,                 '0', '%{Acct-Authentic}',
'%{Connect-Info}',             '', '0', '0',          
'%{Called-Station-Id}', '%{Calling-Station-Id}', '',            
'%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}',               
'%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}') ->      
INSERT INTO radacct             (acctsessionid, acctuniqueid,           
username,               realm,                  nasipaddress,          
nasportid,      nasporttype,             acctstarttime,         
acctstoptime,           acctsessiontime,        acctauthentic, 
connectinfo_start,               connectinfo_stop,       acctinputoctets,       
acctoutputoctets,               calledstationid,         callingstationid,      
acctterminatecause,             servicetype,            framedprotocol,         
framedipaddress,                acctstartdelay,         acctstopdelay,         
xascendsessionsvrkey)    VALUES          ('000033C8',
'df4dee5fb72121b17bd275a4d64782c6',                'user',                
'', '10.169.33.11', '13431',             'Wireless-802.11', '2011-12-08
17:26:25', NULL,                 '0', 'RADIUS', '',               '', '0',
'0',           '0013.1a08.9340', '001b.7770.9159', '',                
'Framed-User', '', '',           '0', '0', '')
Thu Dec  8 17:26:25 2011 : Debug: rlm_sql (sql): Reserved connection (12)
Thu Dec  8 17:26:25 2011 : Debug: rlm_sql (sql): Released connection (12)
Thu Dec  8 17:26:25 2011 : Info: (38)   [sql] = ok
Thu Dec  8 17:26:25 2011 : Info: (38) sql_log : Processing
sql_log_accounting
Thu Dec  8 17:26:25 2011 : Info: (38) sql_log :         expand: %{User-Name}
-> user
Thu Dec  8 17:26:25 2011 : Info: (38) sql_log :         expand:
%{%{User-Name}:-DEFAULT} -> user
Thu Dec  8 17:26:25 2011 : Info: (38) sql_log : sql_set_user escaped user
--> 'user'
Thu Dec  8 17:26:25 2011 : Info: (38) sql_log :         expand: INSERT INTO
radacct (AcctSessionId, UserName,    NASIPAddress, FramedIPAddress,
AcctStartTime, AcctStopTime,      AcctSessionTime, AcctTerminateCause)
VALUES                      ('%{Acct-Session-Id}', '%{User-Name}',
'%{NAS-IP-Address}',     '%{Framed-IP-Address}', '%S', '0', '0', ''); ->
INSERT INTO radacct (AcctSessionId, UserName,    NASIPAddress,
FramedIPAddress, AcctStartTime, AcctStopTime,      AcctSessionTime,
AcctTerminateCause) VALUES                     ('000033C8', 'user',
'10.169.33.11',     '', '2011-12-08 17:26:25', '0', '0', '');
Thu Dec  8 17:26:25 2011 : Info: (38) sql_log :         expand:
/usr/local/var/log/radius/radacct/sql-relay ->
/usr/local/var/log/radius/radacct/sql-relay
Thu Dec  8 17:26:25 2011 : Info: (38)   [sql_log] = ok
Thu Dec  8 17:26:25 2011 : Info: (38)   [exec] = noop
Thu Dec  8 17:26:25 2011 : Info: (38) attr_filter.accounting_response :        
expand: %{User-Name} -> user
Thu Dec  8 17:26:25 2011 : Info: (38) attr_filter.accounting_response :
Matched entry DEFAULT at line 12
Thu Dec  8 17:26:25 2011 : Info: (38)   [attr_filter.accounting_response] =
updated
Sending Accounting-Response of id 172 to 10.169.33.11 port 1646
Thu Dec  8 17:26:25 2011 : Info: (38) Finished request 38.
Thu Dec  8 17:26:26 2011 : Debug: Waking up in 0.2 seconds.
Thu Dec  8 17:26:26 2011 : Info: (38) Cleaning up request packet ID 172 with
timestamp +765
Thu Dec  8 17:26:26 2011 : Debug: Waking up in 3.9 seconds.
Thu Dec  8 17:26:30 2011 : Info: (27) Cleaning up request packet ID 95 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Info: (28) Cleaning up request packet ID 96 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Info: (29) Cleaning up request packet ID 97 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Info: (30) Cleaning up request packet ID 98 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Info: (31) Cleaning up request packet ID 99 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Info: (32) Cleaning up request packet ID 100 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Info: (33) Cleaning up request packet ID 101 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Info: (34) Cleaning up request packet ID 102 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Debug: Waking up in 0.3 seconds.
Thu Dec  8 17:26:30 2011 : Info: (35) Cleaning up request packet ID 103 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Info: (36) Cleaning up request packet ID 104 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Debug: Waking up in 0.2 seconds.
Thu Dec  8 17:26:30 2011 : Info: (37) Cleaning up request packet ID 105 with
timestamp +765
Thu Dec  8 17:26:30 2011 : Info: Ready to process requests.

freebsd# radwho
Login      Name              What  TTY  When      From            Location
user       user              shell >999 Thu 14:38 10.169.33.11    
user       user              shell >999 Thu 15:03 10.169.33.11    
user       user              shell >999 Thu 17:25 10.169.33.11    
user       user              shell >999 Thu 17:26 10.169.33.11   

what can be an issue?

thanks




--
View this message in context: http://freeradius.1045715.n5.nabble.com/semulteneius-use-with-cisco-nas-tp5062116p5062116.html
Sent from the FreeRadius - User mailing list archive at Nabble.com.



More information about the Freeradius-Users mailing list