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