Re[8]: semulteneius-use with cisco nas

Толик Шавловский tolik_shavlovsky at mail.ru
Wed Dec 14 10:05:51 CET 2011


Dear Fajar,

here is the debug:
=================
rad_recv: Access-Request packet from host 10.169.33.11 port 1645, id=242, 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 = 0x1b9f8a18ab599eb355a6b95009ad3876
        EAP-Message = 0x020c00261900170301001bb38d66eaaca02000d41d031c3b819c732c2073d8ae808cdf61d43a
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 13495
        State = 0xc9003ff4c00c263b902065cf0bcf43fd
        NAS-IP-Address = 10.169.33.11
        NAS-Identifier = "ap"
(49) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default
(49)   group authorize {
(49)  - entering group authorize {...}
(49)   [preprocess] = ok
(49)   [chap] = noop
(49)   [mschap] = noop
(49)   [digest] = noop
(49) suffix : No '@' in User-Name = "user", looking up realm NULL
(49) suffix : No such realm "NULL"
(49)   [suffix] = noop
(49) eap : EAP packet type response id 12 length 38
(49) eap : Continuing tunnel setup.
(49)   [eap] = ok
(49) Found Auth-Type = ?
(49) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(49)   group authenticate {
(49)  - entering group authenticate {...}
(49) eap : Request found, released from the list
(49) eap : EAP/peap
(49) eap : processing type peap
(49) peap : processing EAP-TLS
(49) peap : eaptls_verify returned 7 
(49) peap : Done initial handshake
(49) peap : eaptls_process returned 7 
(49) peap : FR_TLS_OK
(49) peap : Session established.  Decoding tunneled attributes.
(49) peap : Peap state send tlv success
(49) peap : Received EAP-TLV response.
(49) peap : Success
(49) peap : Using saved attributes from the original Access-Accept
        User-Name = "user"
(49) eap : Freeing handler
(49)   [eap] = ok
(49) Login OK: [user/<via Auth-Type = ?>] (from client 10.169.33.11/24 port 13495 cli 001b.7770.9159)
(49) # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default
(49)   group post-auth {
(49)  - entering group post-auth {...}
(49) sql :      expand: %{User-Name} -> user
(49) sql : sql_set_user escaped user --> 'user'
(49) sql :      expand: %{User-Password} -> 
(49) sql :      ... expanding second conditional
(49) sql :      expand: %{Chap-Password} -> 
(49) 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-14 10:59:49')
rlm_sql (sql) in sql_postauth: query is         INSERT INTO radpostauth         (username, pass, reply, authdate)   VALUES (        'user',         '',     'Access-Accept', '2011-12-14 10:59:49')
rlm_sql (sql): Reserved connection (12)
rlm_sql (sql): Released connection (12)
(49)   [sql] = ok
(49) sql_log : Processing sql_log_postauth
(49) sql_log :  expand: %{User-Name} -> user
(49) sql_log :  expand: %{%{User-Name}:-DEFAULT} -> user
(49) sql_log : sql_set_user escaped user --> 'user'
(49) sql_log : WARNING: Deprecated conditional expansion ":-".  See "man unlang" for details
(49) sql_log :  ... expanding second conditional
(49) sql_log :  expand: Chap-Password -> Chap-Password
(49) 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-14 10:59:49');
(49) sql_log :  expand: /usr/local/var/log/radius/radacct/sql-relay -> /usr/local/var/log/radius/radacct/sql-relay
(49)   [sql_log] = ok
(49)   [exec] = noop
(49)    policy remove_reply_message_if_eap {
(49)   - entering policy remove_reply_message_if_eap {...}
(49)    ? if (reply:EAP-Message && reply:Reply-Message)
(49) ? Evaluating (reply:EAP-Message ) -> TRUE
(49) ? Evaluating (reply:Reply-Message) -> FALSE
(49)    ? if (reply:EAP-Message && reply:Reply-Message) -> FALSE
(49)     else else {
(49)    - entering else else {...}
(49)     [noop] = noop
(49)    - else else returns noop
(49)   - policy remove_reply_message_if_eap returns noop
Sending Access-Accept of id 242 to 10.169.33.11 port 1645
        User-Name = "user"
        MS-MPPE-Recv-Key = 0xffb3f4f01af8ea5b71cfe309205a5436aad8c57caf0cf40d6b37fbd193df34f6
        MS-MPPE-Send-Key = 0x500ebf88f7a74a9095d357c31ac48010e62b655ebd53573d2d418a1e1332c732
        EAP-Message = 0x030c0004
        Message-Authenticator = 0x00000000000000000000000000000000
(49) Finished request 49.
Waking up in 0.1 seconds.
rad_recv: Accounting-Request packet from host 10.169.33.11 port 1646, id=204, length=224
        Acct-Session-Id = "00003414"
        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 = "13495"
        NAS-Port = 13495
        Service-Type = Framed-User
        NAS-IP-Address = 10.169.33.11
        Acct-Delay-Time = 0
(50) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default
(50)   group preacct {
(50)  - entering group preacct {...}
(50)   [preprocess] = ok
(50)    policy acct_unique {
(50)   - entering policy acct_unique {...}
(50)    ? if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i)
(50)    expand: %{string:Class} -> 
(50) ? Evaluating ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE
(50)    ? if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE
(50)     else else {
(50)    - entering else else {...}
(50)     update request {
(50)    expand: %{User-Name}%{Acct-Session-ID}%{NAS-IP-Address}%{NAS-Port-ID:}%{NAS-Port} -> user0000341410.169.33.1113495
(50)    expand: %{md5:%{User-Name}%{Acct-Session-ID}%{NAS-IP-Address}%{NAS-Port-ID:}%{NAS-Port}} -> 15f0e8167a1f7da83d358d77ecdc4f3e
(50)     } # update request = ok
(50)    - else else returns ok
(50)   - policy acct_unique returns ok
(50) suffix : No '@' in User-Name = "user", looking up realm NULL
(50) suffix : No such realm "NULL"
(50)   [suffix] = noop
(50)   [files] = noop
(50) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default
(50)   group accounting {
(50)  - entering group accounting {...}
(50) detail :   expand: %{Packet-Src-IP-Address} -> 10.169.33.11
(50) 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-20111214
(50) 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-20111214
(50) detail :   expand: %t -> Wed Dec 14 10:59:49 2011
(50)   [detail] = ok
(50)   [unix] = ok
(50) radutmp :  expand: /usr/local/var/log/radius/radutmp -> /usr/local/var/log/radius/radutmp
(50) radutmp :  expand: %{User-Name} -> user
(50)   [radutmp] = ok
(50) sql :      expand: %{User-Name} -> user
(50) sql : sql_set_user escaped user --> 'user'
(50) sql :      expand: %{Acct-Delay-Time} -> 0
(50) 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          ('00003414', '15f0e8167a1f7da83d358d77ecdc4f3e',                'user',    '', '10.169.33.11', '13495',             'Wireless-802.11', '2011-12-14 10:59:49', NULL,            '0', 'RADIUS', '',               '', '0', '0',   
        '0013.1a08.9340', '001b.7770.9159', '',    'Framed-User', '', '',           '0', '0', '')
rlm_sql (sql): Reserved connection (12)
rlm_sql (sql): Released connection (12)
(50)   [sql] = ok
(50) sql_log : Processing sql_log_accounting
(50) sql_log :  expand: %{User-Name} -> user
(50) sql_log :  expand: %{%{User-Name}:-DEFAULT} -> user
(50) sql_log : sql_set_user escaped user --> 'user'
(50) 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                         ('00003414', 'user', '10.169.33.11',    '', '2011-12-14 10:59:49', '0', '0', '');
(50) sql_log :  expand: /usr/local/var/log/radius/radacct/sql-relay -> /usr/local/var/log/radius/radacct/sql-relay
(50)   [sql_log] = ok
(50)   [exec] = noop
(50) attr_filter.accounting_response :  expand: %{User-Name} -> user
(50) attr_filter.accounting_response : Matched entry DEFAULT at line 12
(50)   [attr_filter.accounting_response] = updated
Sending Accounting-Response of id 204 to 10.169.33.11 port 1646
(50) Finished request 50.
(50) Cleaning up request packet ID 204 with timestamp +1745
Waking up in 4.4 seconds.
(39) Cleaning up request packet ID 232 with timestamp +1745
(40) Cleaning up request packet ID 233 with timestamp +1745
(41) Cleaning up request packet ID 234 with timestamp +1745
(42) Cleaning up request packet ID 235 with timestamp +1745
(43) Cleaning up request packet ID 236 with timestamp +1745
(44) Cleaning up request packet ID 237 with timestamp +1745
(45) Cleaning up request packet ID 238 with timestamp +1745
(46) Cleaning up request packet ID 239 with timestamp +1745
(47) Cleaning up request packet ID 240 with timestamp +1745
(48) Cleaning up request packet ID 241 with timestamp +1745
(49) Cleaning up request packet ID 242 with timestamp +1745
Ready to process requests.
====================================

SQL doesn't SELECT COUNT(*) from radacct. Is this a  problem of  sql configuration?



14 декабря 2011, 12:47 от "Fajar A. Nugraha" <list at fajar.net>:
> On Wed, Dec 14, 2011 at 3:34 PM, tolik_shavlovsky at mail.ru
> <tolik_shavlovsky at mail.ru> wrote:
> > Hi Fajar,
> >
> > i made everything from:
> >
> > - enable sql in accounting section of sites-available/default
> > - enable sql in session section of sites-available/default (and
> > sites-available/inner-tunnel, if you use EAP)
> > - uncomment simul_count_query in sql /*/ dialup.conf
> >
> > but it doesn't work((
> 
> What does the debug log say? DId you still have Simultaneous-Use := 1
> in radcheck for that user?
> 
> Your last debug log doesn't mention anything about sql in session
> section. It should have something like this:
> 
> # Executing section session from file /etc/freeradius/sites-enabled/default
> +- entering group session {...}
> [sql] 	expand: %{User-Name} -> testuser
> [sql] sql_set_user escaped user --> 'testuser'
> [sql] 	expand: SELECT COUNT(*)                              #FROM
> radacct                              #WHERE username =
> '%{SQL-User-Name}'                              #AND acctstoptime IS
> NULL -> SELECT COUNT(*)                              #FROM radacct
>                          #WHERE username = 'testuser'
>             #AND acctstoptime IS NULL
> 
> ... and so on
> 
> --
> Fajar
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
> 




More information about the Freeradius-Users mailing list