HI Alan, log with simultaneous-Use := 1: rad_recv: Accounting-Request packet from host xxx.xxx.xxx.xxx port 40165, id=56, length=327 Acct-Status-Type = Start Acct-Session-Id = "21613e25-697e-4d90-a741-586503d4abcb" User-Name = "018108753.enterprise" Freeswitch-Src = "018108753.enterprise" Freeswitch-CLID = "018108753.enterprise" Freeswitch-Dst = "031681796" Freeswitch-Dialplan = "XML" Framed-IP-Address = 84.41.126.2 Freeswitch-Context = "enterprise.fs2.softnet.si" Freeswitch-Ani = "018108753.enterprise" Freeswitch-Source = "mod_sofia" Freeswitch-Callstartdate = "2012-11-03T21:07:03.383945+0100" NAS-Port = 0 Acct-Delay-Time = 0 NAS-IP-Address = xxx.xxx.xxx.xxx # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default +- entering group preacct {...} ++[preprocess] returns ok [acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address = xxx.xxx.xxx.xxx,NAS-IP-Address = xxx.xxx.xxx.xxx,Acct-Session-Id = "21613e25-697e-4d90-a741-586503d4abcb",User-Name = "018108753.enterprise"' [acct_unique] Acct-Unique-Session-ID = "ccb7c871be618e52". ++[acct_unique] returns ok [suffix] No '@' in User-Name = "018108753.enterprise", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop ++[files] returns noop # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default +- entering group accounting {...} [detail] expand: %{Packet-Src-IP-Address} -> xxx.xxx.xxx.xxx [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/xxxx.xxxx.xxxx.xxxx/detail-20121103 [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/xxxx.xxxx.xxxx.xxxx/detail-20121103 [detail] expand: %t -> Sat Nov 3 21:01:26 2012 ++[detail] returns ok ++[unix] returns ok [radutmp] expand: /usr/local/var/log/radius/radutmp -> /usr/local/var/log/radius/radutmp [radutmp] expand: %{User-Name} -> 018108753.enterprise ++[radutmp] returns ok [sql] expand: %{User-Name} -> 018108753.enterprise [sql] sql_set_user escaped user --> '018108753.enterprise' [sql] expand: %{Acct-Delay-Time} -> 0 [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}', '%{Freeswitch-Src}', '%{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}', rlm_sql (sql): Reserving sql socket id: 4 rlm_sql (sql): Released sql socket id: 4 ++[sql] returns ok ++[exec] returns noop [attr_filter.accounting_response] expand: %{User-Name} -> 018108753.enterprise attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 56 to xxx.xxx.xxx.xxx port 40165 Finished request 0. Cleaning up request 0 ID 56 with timestamp +2994 Going to the next request Ready to process requests. rad_recv: Access-Request packet from host xxx.xxx.xxx.xxx port 43949, id=57, length=193 User-Name = "018108753.enterprise" User-Password = "xxxxxxx" h323-conf-id = "h323-conf-id=21613e25-697e-4d90-a741-586503d4abcb" h323-prompt-id = "h323-prompt-id=031681796" NAS-Port-Type = Async NAS-Port-Id = "ISDN 3/0:D:14" User-Name = "1" NAS-Port = 0 NAS-IP-Address = xxxx.xxxx.xxxx.xxxx # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "018108753.enterprise", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop ++[files] returns noop [sql] expand: %{User-Name} -> 018108753.enterprise [sql] sql_set_user escaped user --> '018108753.enterprise' rlm_sql (sql): Reserving sql socket id: 3 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '018108753.enterprise' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '018108753.enterprise' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '018108753.enterprise' ORDER BY priority [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'testservice' ORDER BY id [sql] User found in group testservice [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'testservice' ORDER BY id rlm_sql (sql): Released sql socket id: 3 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop ++[pap] returns updated Found Auth-Type = PAP # Executing group from file /usr/local/etc/raddb/sites-enabled/default +- entering group PAP {...} [pap] login attempt with password "52166" [pap] Using clear text password "52166" [pap] User authenticated successfully ++[pap] returns ok # Executing section session from file /usr/local/etc/raddb/sites-enabled/default +- entering group session {...} [radutmp] expand: /usr/local/var/log/radius/radutmp -> /usr/local/var/log/radius/radutmp [radutmp] expand: %{User-Name} -> 018108753.enterprise checkrad: No NAS type, or type "other" not checking ++[radutmp] returns ok Using Post-Auth-Type Reject # Executing group from file /usr/local/etc/raddb/sites-enabled/default +- entering group REJECT {...} ++- group REJECT returns noop Delaying reject of request 1 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 1 Sending Access-Reject of id 57 to xxxx.xxxx.xxxx.xxxx port 43949 Reply-Message := "\r\nYou are already logged in - access denied\r\n\n" Waking up in 4.9 seconds. Cleaning up request 1 ID 57 with timestamp +2994 Ready to process requests. ------- simultaneous-Use := 2 rad_recv: Accounting-Request packet from host xxx.xxx.xxx.xxx port 56503, id=58, length=327 Acct-Status-Type = Start Acct-Session-Id = "5eb406e9-c555-4471-a7c6-8d475cdf506f" User-Name = "018108753.enterprise" Freeswitch-Src = "018108753.enterprise" Freeswitch-CLID = "018108753.enterprise" Freeswitch-Dst = "031681796" Freeswitch-Dialplan = "XML" Framed-IP-Address = 84.41.126.2 Freeswitch-Context = "enterprise.fs2.softnet.si" Freeswitch-Ani = "018108753.enterprise" Freeswitch-Source = "mod_sofia" Freeswitch-Callstartdate = "2012-11-03T21:07:50.523808+0100" NAS-Port = 0 Acct-Delay-Time = 0 NAS-IP-Address = xxx.xxx.xxx.xxx # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default +- entering group preacct {...} ++[preprocess] returns ok [acct_unique] Hashing 'NAS-Port = 0,Client-IP-Address = xxx.xxx.xxx.xxx,NAS-IP-Address = xxx.xxx.xxx.xxx,Acct-Session-Id = "5eb406e9-c555-4471-a7c6-8d475cdf506f",User-Name = "018108753.enterprise"' [acct_unique] Acct-Unique-Session-ID = "3168bcb9932a1636". ++[acct_unique] returns ok [suffix] No '@' in User-Name = "018108753.enterprise", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop ++[files] returns noop # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default +- entering group accounting {...} [detail] expand: %{Packet-Src-IP-Address} -> xxx.xxx.xxx.xxx [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/xxx.xxx.xxx.xxx/detail-20121103 [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/xxx.xxx.xxx.xxx/detail-20121103 [detail] expand: %t -> Sat Nov 3 21:02:13 2012 ++[detail] returns ok ++[unix] returns ok [radutmp] expand: /usr/local/var/log/radius/radutmp -> /usr/local/var/log/radius/radutmp [radutmp] expand: %{User-Name} -> 018108753.enterprise ++[radutmp] returns ok [sql] expand: %{User-Name} -> 018108753.enterprise [sql] sql_set_user escaped user --> '018108753.enterprise' [sql] expand: %{Acct-Delay-Time} -> 0 [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}', '%{Freeswitch-Src}', '%{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}', rlm_sql (sql): Reserving sql socket id: 2 rlm_sql (sql): Released sql socket id: 2 ++[sql] returns ok ++[exec] returns noop [attr_filter.accounting_response] expand: %{User-Name} -> 018108753.enterprise attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 58 to xxx.xxx.xxx.xxx port 56503 Finished request 2. Cleaning up request 2 ID 58 with timestamp +3041 Going to the next request Ready to process requests. rad_recv: Access-Request packet from host xxx.xxx.xxx.xxx port 37173, id=59, length=193 User-Name = "018108753.enterprise" User-Password = "xxxxxx" h323-conf-id = "h323-conf-id=5eb406e9-c555-4471-a7c6-8d475cdf506f" h323-prompt-id = "h323-prompt-id=031681796" NAS-Port-Type = Async NAS-Port-Id = "ISDN 3/0:D:14" User-Name = "1" NAS-Port = 0 NAS-IP-Address = xxx.xxx.xxx.xxx # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "018108753.enterprise", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop ++[files] returns noop [sql] expand: %{User-Name} -> 018108753.enterprise [sql] sql_set_user escaped user --> '018108753.enterprise' rlm_sql (sql): Reserving sql socket id: 1 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '018108753.enterprise' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = '018108753.enterprise' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '018108753.enterprise' ORDER BY priority [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'testservice' ORDER BY id [sql] User found in group testservice [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'testservice' ORDER BY id rlm_sql (sql): Released sql socket id: 1 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop ++[pap] returns updated Found Auth-Type = PAP # Executing group from file /usr/local/etc/raddb/sites-enabled/default +- entering group PAP {...} [pap] login attempt with password "52166" [pap] Using clear text password "52166" [pap] User authenticated successfully ++[pap] returns ok # Executing section session from file /usr/local/etc/raddb/sites-enabled/default +- entering group session {...} [radutmp] expand: /usr/local/var/log/radius/radutmp -> /usr/local/var/log/radius/radutmp [radutmp] expand: %{User-Name} -> 018108753.enterprise ++[radutmp] returns ok # Executing section post-auth from file /usr/local/etc/raddb/sites-enabled/default +- entering group post-auth {...} ++[exec] returns noop Sending Access-Accept of id 59 to xxx.xxx.xxx.xxx port 37173 Finished request 3. Going to the next request Waking up in 4.9 seconds. Cleaning up request 3 ID 59 with timestamp +3041 Ready to process requests. On Sat, 03 Nov 2012 15:27:41 -0400 Alan DeKok <aland@deployingradius.com> wrote:
Miha wrote:
i am turning out you due to issue with simultaneous-Use. I readed mailing list but did not find any appropriate answer. ... my config:
[root@localhost sites-available]# radiusd -X FreeRADIUS Version 2.1.12, for host ... Ready to process requests.
The reason to post the debug output is to show what happens when the server receives a packet. You didn't show that. So the debug output is useless, and we can't help you.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html