September 2018 - Freeradius-Users - lists.freeradius.org

Issue with Chap Auth - freeradius v3.0.16 on RHEL 7.4
by Andrea Mucci 24 Sep '18

24 Sep '18

Hi All. I have an issue on Chap Authentication Request. It seems that if CHAPChallenge size is longer than 48 bytes, Freeradius sends an Access Reject. I've the samde behavoiur on different client: - an xDSL router on an Alcatel7750 - NetRadPing - freeradius radclient I'm using Freeradius 3.0.16 Follow the logs: 1) xDSL router on an Alcatel7750 (0) Received Access-Request Id 200 from 10.255.254.120:64399 to 198.18.12.36:1812 length 222 (0) User-Name = "20M-GPON-HSI(a)ttp.it" (0) NAS-IP-Address = 10.255.254.120 (0) Service-Type = Framed-User (0) Framed-Protocol = PPP (0) CHAP-Password = 0x0192f8bb1b02e31b15615c5e292de11274 (0) CHAP-Challenge = 0x5c91a970986b4bcc2201b280daf0d9d7adc449b90d45c51ff69a8bb2ae08f68a99a0fb320d477faec83230a3a3897bd0cd458bda8ad07a01ea06339a (0) NAS-Identifier = "RMTB-E31" (0) NAS-Port-Type = Ethernet (0) Acct-Session-Id = "05FF7E0001884C5BA5199A" (0) NAS-Port = 1 (0) NAS-Port-Id = "ISAM-V-DSLAM-01 atm 1/1/02/01:8.35" (0) # Executing section authorize from file /etc/raddb/sites-enabled/default (0) authorize { (0) policy debug-rule { (0) update control { (0) EXPAND %{debug:5} (0) --> 2 (0) Tmp-String-9 = 2 (0) } # update control = noop (0) } # policy debug-rule = noop (0) policy filter_username { (0) if (&User-Name) { (0) if (&User-Name) -> TRUE (0) if (&User-Name) { (0) if (&User-Name =~ / /) { (0) if (&User-Name =~ / /) -> FALSE (0) if (&User-Name =~ /@[^@]*@/ ) { (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (0) if (&User-Name =~ /\.\./ ) { (0) if (&User-Name =~ /\.\./ ) -> FALSE (0) if (&User-Name =~ /\.$/) { (0) if (&User-Name =~ /\.$/) -> FALSE (0) if (&User-Name =~ /(a)\./) { (0) if (&User-Name =~ /(a)\./) -> FALSE (0) } # if (&User-Name) = noop (0) } # policy filter_username = noop (0) modsingle[authorize]: calling preprocess (rlm_preprocess) (0) preprocess: EXPAND ^([^@]*)@((?i)noise.it) (0) preprocess: --> ^([^@]*)@((?i)noise.it) (0) preprocess: EXPAND ^([^@]*)@((?i)ttp.it) (0) preprocess: --> ^([^@]*)@((?i)ttp.it) (0) preprocess: hints: Matched DEFAULT at 9 (0) preprocess: ::: FROM 4 TO 12 MAX 16 (0) preprocess: ::: Examining Hint (0) preprocess: ::: APPENDING Hint FROM 0 TO 12 (0) preprocess: ::: Examining Stripped-User-Name (0) preprocess: 1/3 Found: 20M-GPON-HSI (13) (0) preprocess: EXPAND %{1} (0) preprocess: --> 20M-GPON-HSI (0) preprocess: ::: APPENDING Stripped-User-Name FROM 1 TO 12 (0) preprocess: ::: Examining Realm (0) preprocess: 2/3 Found: ttp.it (7) (0) preprocess: EXPAND %{2} (0) preprocess: --> ttp.it (0) preprocess: ::: APPENDING Realm FROM 2 TO 12 (0) preprocess: ::: Examining HPE-ISPVN-Id (0) preprocess: ::: APPENDING HPE-ISPVN-Id FROM 3 TO 12 (0) preprocess: ::: TO in 12 out 12 (0) preprocess: ::: to[0] = User-Name (0) preprocess: ::: to[1] = NAS-IP-Address (0) preprocess: ::: to[2] = Service-Type (0) preprocess: ::: to[3] = Framed-Protocol (0) preprocess: ::: to[4] = CHAP-Password (0) preprocess: ::: to[5] = CHAP-Challenge (0) preprocess: ::: to[6] = NAS-Identifier (0) preprocess: ::: to[7] = NAS-Port-Type (0) preprocess: ::: to[8] = Acct-Session-Id (0) preprocess: ::: to[9] = NAS-Port (0) preprocess: ::: to[10] = NAS-Port-Id (0) preprocess: ::: to[11] = Event-Timestamp (0) modsingle[authorize]: returned from preprocess (rlm_preprocess) (0) [preprocess] = ok (0) policy nas-info { (0) update control { (0) Cache-Status-Only = yes (0) } # update control = noop (0) modsingle[authorize]: calling cache-nas (rlm_cache) (0) cache-nas: EXPAND %{NAS-IP-Address} (0) cache-nas: --> 10.255.254.120 (0) cache-nas: Mutex acquired (0) cache-nas: No cache entry found for "10.255.254.120" (0) cache-nas: Mutex released (0) modsingle[authorize]: returned from cache-nas (rlm_cache) (0) [cache-nas] = notfound (0) if (notfound) { (0) if (notfound) -> TRUE (0) if (notfound) { (0) update control { (0) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (0) --> 20M-GPON-HSI (0) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (0) (0) EXPAND /var/log/radius/sqllog.sql (0) --> /var/log/radius/sqllog.sql (0) Executing select query: SELECT * FROM DUAL rlm_sql (sql_primary_default): Released connection (0) Need 5 more connections to reach 10 spares rlm_sql (sql_primary_default): Opening additional connection (5), 1 of 27 pending slots used (0) EXPAND %{sql_primary_default:SELECT * FROM DUAL} (0) --> X (0) Tmp-String-0 := X (0) } # update control = noop (0) if (&control:Tmp-String-0 != "") { (0) if (&control:Tmp-String-0 != "") -> TRUE (0) if (&control:Tmp-String-0 != "") { (0) update control { (0) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (0) --> 20M-GPON-HSI (0) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (1) (0) EXPAND /var/log/radius/sqllog.sql (0) --> /var/log/radius/sqllog.sql (0) Executing select query: SELECT VENDOR_ID||'~'||VALUE||'~'||VPDN_VENDOR_CODING_ID FROM NAS a, NAS_TAG b, VPDN_LAC l WHERE A.ID = B.NAS_ID (+) AND B.NAS_TAG_NAME_ID (+) = 1 AND A.ID = L.NAS_ID (+) AND A.IP_ADDR_TXT = '10.255.254.120' rlm_sql (sql_primary_default): Released connection (1) (0) EXPAND %{sql_primary_default:SELECT VENDOR_ID||'~'||VALUE||'~'||VPDN_VENDOR_CODING_ID FROM NAS a, NAS_TAG b, VPDN_LAC l WHERE A.ID = B.NAS_ID (+) AND B.NAS_TAG_NAME_ID (+) = 1 AND A.ID = L.NAS_ID (+) AND A.IP_ADDR_TXT = '%{NAS-IP-Address}'} (0) --> 6527~~ (0) Tmp-String-1 := 6527~~ (0) } # update control = noop (0) } # if (&control:Tmp-String-0 != "") = noop (0) ... skipping else: Preceding "if" was taken (0) if (&control:Tmp-String-1 =~ /([0-9]*)~(.*)~([0-9]*)/) { (0) if (&control:Tmp-String-1 =~ /([0-9]*)~(.*)~([0-9]*)/) -> TRUE (0) if (&control:Tmp-String-1 =~ /([0-9]*)~(.*)~([0-9]*)/) { (0) if ("%{1}" == '' || "%{3}" == '') { (0) EXPAND TMPL XLAT STRUCT (0) 1/4 Found: 6527 (5) (0) EXPAND %{1} (0) --> 6527 (0) EXPAND TMPL XLAT STRUCT (0) 3/4 Found: (1) (0) EXPAND %{3} (0) --> (0) if ("%{1}" == '' || "%{3}" == '') -> TRUE (0) if ("%{1}" == '' || "%{3}" == '') { (0) if ("%{1}" == '') { (0) EXPAND TMPL XLAT STRUCT (0) 1/4 Found: 6527 (5) (0) EXPAND %{1} (0) --> 6527 (0) if ("%{1}" == '') -> FALSE (0) else { (0) update control { (0) 1/4 Found: 6527 (5) (0) EXPAND %{1} (0) --> 6527 (0) Tmp-Integer-2 := 6527 (0) 2/4 Found: (1) (0) EXPAND %{2} (0) --> (0) Tmp-String-2 := (0) Tmp-Integer-3 := 0 (0) } # update control = noop (0) } # else = noop (0) } # if ("%{1}" == '' || "%{3}" == '') = noop (0) ... skipping else: Preceding "if" was taken (0) } # if (&control:Tmp-String-1 =~ /([0-9]*)~(.*)~([0-9]*)/) = noop (0) ... skipping else: Preceding "if" was taken (0) } # if (notfound) = noop (0) modsingle[authorize]: calling cache-nas (rlm_cache) (0) cache-nas: EXPAND %{NAS-IP-Address} (0) cache-nas: --> 10.255.254.120 (0) cache-nas: Mutex acquired (0) cache-nas: No cache entry found for "10.255.254.120" (0) cache-nas: Creating new cache entry (0) cache-nas: &control:HPE-NAS-VendorId := &control:Tmp-Integer-2 -> 6527 (0) cache-nas: &control:HPE-NAS-DNS-Zone := &control:Tmp-String-2 -> '' (0) cache-nas: &control:HPE-NAS-VendorCodingId := &control:Tmp-Integer-3 -> 0 (0) cache-nas: Merging cache entry into request (0) cache-nas: &control:HPE-NAS-VendorId := 6527 (0) cache-nas: &control:HPE-NAS-DNS-Zone := "" (0) cache-nas: &control:HPE-NAS-VendorCodingId := 0 (0) cache-nas: ::: FROM 3 TO 6 MAX 9 (0) cache-nas: ::: Examining HPE-NAS-VendorId (0) cache-nas: ::: APPENDING HPE-NAS-VendorId FROM 0 TO 6 (0) cache-nas: ::: Examining HPE-NAS-DNS-Zone (0) cache-nas: ::: APPENDING HPE-NAS-DNS-Zone FROM 1 TO 6 (0) cache-nas: ::: Examining HPE-NAS-VendorCodingId (0) cache-nas: ::: APPENDING HPE-NAS-VendorCodingId FROM 2 TO 6 (0) cache-nas: ::: TO in 6 out 6 (0) cache-nas: ::: to[0] = Tmp-String-9 (0) cache-nas: ::: to[1] = Tmp-String-0 (0) cache-nas: ::: to[2] = Tmp-String-1 (0) cache-nas: ::: to[3] = Tmp-Integer-2 (0) cache-nas: ::: to[4] = Tmp-String-2 (0) cache-nas: ::: to[5] = Tmp-Integer-3 (0) cache-nas: Committed entry, TTL 60 seconds (0) cache-nas: Mutex released (0) modsingle[authorize]: returned from cache-nas (rlm_cache) (0) [cache-nas] = updated (0) } # policy nas-info = updated (0) policy auth-by-callingId { (0) if (&Calling-Station-ID){ (0) if (&Calling-Station-ID) -> FALSE (0) else { (0) update control { (0) HPE-Auth-By-CliId := No (0) } # update control = noop (0) } # else = noop (0) } # policy auth-by-callingId = noop (0) if (&control:HPE-Auth-By-CliId == "Yes") { (0) if (&control:HPE-Auth-By-CliId == "Yes") -> FALSE (0) else { (0) if (&request:Hint == "ROAM") { (0) if (&request:Hint == "ROAM") -> FALSE (0) elsif (&request:Hint == "VPDN") { (0) elsif (&request:Hint == "VPDN") -> FALSE (0) else { (0) if (&request:HPE-ISPVN-Id == 1000912) { (0) if (&request:HPE-ISPVN-Id == 1000912) -> FALSE (0) else { (0) redundant redundant_sql_default { (0) modsingle[authorize]: calling sql_primary_default (rlm_sql) (0) sql_primary_default: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (0) sql_primary_default: --> 20M-GPON-HSI (0) sql_primary_default: SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (2) (0) sql_primary_default: EXPAND SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY id (0) sql_primary_default: --> SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (0) sql_primary_default: Executing select query: SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (0) sql_primary_default: User found in radcheck table (0) sql_primary_default: Conditional check items matched, merging assignment check items (0) sql_primary_default: Cleartext-Password := "test" (0) sql_primary_default: ::: FROM 1 TO 10 MAX 11 (0) sql_primary_default: ::: Examining Cleartext-Password (0) sql_primary_default: ::: APPENDING Cleartext-Password FROM 0 TO 10 (0) sql_primary_default: ::: TO in 10 out 10 (0) sql_primary_default: ::: to[0] = Tmp-String-9 (0) sql_primary_default: ::: to[1] = Tmp-String-0 (0) sql_primary_default: ::: to[2] = Tmp-String-1 (0) sql_primary_default: ::: to[3] = Tmp-Integer-2 (0) sql_primary_default: ::: to[4] = Tmp-String-2 (0) sql_primary_default: ::: to[5] = Tmp-Integer-3 (0) sql_primary_default: ::: to[6] = HPE-NAS-VendorId (0) sql_primary_default: ::: to[7] = HPE-NAS-DNS-Zone (0) sql_primary_default: ::: to[8] = HPE-NAS-VendorCodingId (0) sql_primary_default: ::: to[9] = HPE-Auth-By-CliId (0) sql_primary_default: EXPAND SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,%{&control:HPE-Nas-VendorId}) AND lower(s.username) = '%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY id (0) sql_primary_default: --> SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,6527) AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (0) sql_primary_default: Executing select query: SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,6527) AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (0) sql_primary_default: ... falling-through to group processing (0) sql_primary_default: EXPAND SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY priority (0) sql_primary_default: --> SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY priority (0) sql_primary_default: Executing select query: SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY priority (0) sql_primary_default: User found in the group table (0) sql_primary_default: EXPAND SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = '%{sql_primary_default-SQL-Group}' ORDER BY id (0) sql_primary_default: --> SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (0) sql_primary_default: Executing select query: SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (0) sql_primary_default: Group "RAC x 20M-GPON-HSI": Conditional check items matched (0) sql_primary_default: Group "RAC x 20M-GPON-HSI": Merging assignment check items (0) sql_primary_default: ::: FROM 0 TO 11 MAX 11 (0) sql_primary_default: ::: TO in 11 out 11 (0) sql_primary_default: ::: to[0] = Tmp-String-9 (0) sql_primary_default: ::: to[1] = Tmp-String-0 (0) sql_primary_default: ::: to[2] = Tmp-String-1 (0) sql_primary_default: ::: to[3] = Tmp-Integer-2 (0) sql_primary_default: ::: to[4] = Tmp-String-2 (0) sql_primary_default: ::: to[5] = Tmp-Integer-3 (0) sql_primary_default: ::: to[6] = HPE-NAS-VendorId (0) sql_primary_default: ::: to[7] = HPE-NAS-DNS-Zone (0) sql_primary_default: ::: to[8] = HPE-NAS-VendorCodingId (0) sql_primary_default: ::: to[9] = HPE-Auth-By-CliId (0) sql_primary_default: ::: to[10] = Cleartext-Password (0) sql_primary_default: EXPAND SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,%{&control:HPE-Nas-VendorId}) AND rg.name = '%{sql_primary_default-SQL-Group}' ORDER BY id (0) sql_primary_default: --> SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,6527) AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (0) sql_primary_default: Executing select query: SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,6527) AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (0) sql_primary_default: Group "RAC x 20M-GPON-HSI": Merging reply items (0) sql_primary_default: Acct-Interim-Interval = 21600 (0) sql_primary_default: Alc-Primary-Dns = 193.70.152.15 (0) sql_primary_default: Alc-Secondary-Dns = 212.52.97.15 (0) sql_primary_default: Alc-SLA-Prof-Str = "20M-GPON-HSI" (0) sql_primary_default: Alc-Subsc-Prof-Str = "sub-Gpon" (0) sql_primary_default: ::: FROM 5 TO 0 MAX 5 (0) sql_primary_default: ::: Examining Acct-Interim-Interval (0) sql_primary_default: ::: APPENDING Acct-Interim-Interval FROM 0 TO 0 (0) sql_primary_default: ::: Examining Alc-Primary-Dns (0) sql_primary_default: ::: APPENDING Alc-Primary-Dns FROM 1 TO 0 (0) sql_primary_default: ::: Examining Alc-Secondary-Dns (0) sql_primary_default: ::: APPENDING Alc-Secondary-Dns FROM 2 TO 0 (0) sql_primary_default: ::: Examining Alc-SLA-Prof-Str (0) sql_primary_default: ::: APPENDING Alc-SLA-Prof-Str FROM 3 TO 0 (0) sql_primary_default: ::: Examining Alc-Subsc-Prof-Str (0) sql_primary_default: ::: APPENDING Alc-Subsc-Prof-Str FROM 4 TO 0 (0) sql_primary_default: ::: TO in 0 out 0 (0) sql_primary_default: ... falling-through to profile processing rlm_sql (sql_primary_default): Released connection (2) (0) modsingle[authorize]: returned from sql_primary_default (rlm_sql) (0) [sql_primary_default] = ok (0) } # redundant redundant_sql_default = ok (0) policy check-block { (0) if (&control:HPE-Block-Subscriber && &control:HPE-Block-Subscriber == "Y") { (0) if (&control:HPE-Block-Subscriber && &control:HPE-Block-Subscriber == "Y") -> FALSE (0) } # policy check-block = ok (0) } # else = ok (0) } # else = ok (0) } # else = ok (0) modsingle[authorize]: calling chap (rlm_chap) (0) chap: &control:Auth-Type := CHAP (0) modsingle[authorize]: returned from chap (rlm_chap) (0) [chap] = ok (0) modsingle[authorize]: calling expiration (rlm_expiration) (0) modsingle[authorize]: returned from expiration (rlm_expiration) (0) [expiration] = noop (0) modsingle[authorize]: calling logintime (rlm_logintime) (0) modsingle[authorize]: returned from logintime (rlm_logintime) (0) [logintime] = noop (0) modsingle[authorize]: calling pap (rlm_pap) (0) pap: WARNING: Auth-Type already set. Not setting to PAP (0) modsingle[authorize]: returned from pap (rlm_pap) (0) [pap] = noop (0) } # authorize = updated (0) Found Auth-Type = CHAP (0) # Executing group from file /etc/raddb/sites-enabled/default (0) Auth-Type CHAP { (0) modsingle[authenticate]: calling chap (rlm_chap) (0) chap: Comparing with "known good" &control:Cleartext-Password value "test" (0) chap: Using challenge from &request:CHAP-Challenge (0) chap: CHAP challenge : 5c91a970986b4bcc2201b280daf0d9d7adc449b90d45c51ff69a8bb2ae08f68a99a0fb320d477faec83230a3a3897bd0cd458bda8ad07a01ea06339a (0) chap: Client sent : 92f8bb1b02e31b15615c5e292de11274 (0) chap: We calculated : 36396138626232616530386636386139 (0) chap: ERROR: Password comparison failed: password is incorrect (0) modsingle[authenticate]: returned from chap (rlm_chap) (0) [chap] = reject (0) } # Auth-Type CHAP = reject (0) Failed to authenticate the user (0) Using Post-Auth-Type Reject (0) # Executing group from file /etc/raddb/sites-enabled/default (0) Post-Auth-Type REJECT { (0) policy insert_hpe_reply_message { (0) update control { (0) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (0) --> 20M-GPON-HSI (0) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (3) (0) EXPAND /var/log/radius/sqllog.sql (0) --> /var/log/radius/sqllog.sql (0) Executing select query: SELECT * FROM DUAL rlm_sql (sql_primary_default): Released connection (3) (0) EXPAND %{sql_primary_default:SELECT * FROM DUAL} (0) --> X (0) Tmp-String-0 := X (0) Overwriting value "X" with "X" (0) } # update control = noop (0) if (&request:Hint == "Access") { (0) if (&request:Hint == "Access") -> TRUE (0) if (&request:Hint == "Access") { (0) if (&control:Tmp-String-0 != "") { (0) if (&control:Tmp-String-0 != "") -> TRUE (0) if (&control:Tmp-String-0 != "") { (0) update reply { (0) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (0) --> 20M-GPON-HSI (0) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (4) (0) EXPAND /var/log/radius/sqllog.sql (0) --> /var/log/radius/sqllog.sql (0) Executing select query: SELECT create_message_reply('Access',1059241,'20M-GPON-HSI','','No','test','chap: Password comparison failed: password is incorrect') FROM DUAL rlm_sql (sql_primary_default): Released connection (4) (0) EXPAND %{sql_primary_default:SELECT create_message_reply('%{Hint}',%{HPE-ISPVN-Id},'%{%{Stripped-User-Name}:-%{User-Name}}','%{Calling-Station-ID}','%{&control:HPE-Auth-By-CliId}','%{%{&control:Cleartext-Password}:-''}','%{Module-Failure-Message}') FROM DUAL} (0) --> A_1059241_72924453_1058360_test_2 (0) &Reply-Message = A_1059241_72924453_1058360_test_2 (0) } # update reply = noop (0) } # if (&control:Tmp-String-0 != "") = noop (0) ... skipping else: Preceding "if" was taken (0) } # if (&request:Hint == "Access") = noop (0) ... skipping elsif: Preceding "if" was taken (0) ... skipping elsif: Preceding "if" was taken (0) } # policy insert_hpe_reply_message = noop (0) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) (0) attr_filter.access_reject: EXPAND %{User-Name} (0) attr_filter.access_reject: --> 20M-GPON-HSI(a)ttp.it (0) attr_filter.access_reject: Matched entry DEFAULT at line 11 (0) attr_filter.access_reject: Attribute "Acct-Interim-Interval" allowed by 0 rules, disallowed by 0 rules (0) attr_filter.access_reject: Attribute "Alc-Primary-Dns" allowed by 0 rules, disallowed by 0 rules (0) attr_filter.access_reject: Attribute "Alc-Secondary-Dns" allowed by 0 rules, disallowed by 0 rules (0) attr_filter.access_reject: Attribute "Alc-SLA-Prof-Str" allowed by 0 rules, disallowed by 0 rules (0) attr_filter.access_reject: Attribute "Alc-Subsc-Prof-Str" allowed by 0 rules, disallowed by 0 rules (0) attr_filter.access_reject: Reply-Message = "A_1059241_72924453_1058360_test_2" allowed by Reply-Message =* "" (0) attr_filter.access_reject: Attribute "Reply-Message" allowed by 1 rules, disallowed by 0 rules (0) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) (0) [attr_filter.access_reject] = updated (0) } # Post-Auth-Type REJECT = updated (0) Delaying response for 1.000000 seconds Waking up in 0.2 seconds. Waking up in 0.7 seconds. (0) Sending delayed response (0) Sent Access-Reject Id 200 from 198.18.12.36:1812 to 10.255.254.120:64399 length 55 (0) Reply-Message = "A_1059241_72924453_1058360_test_2" Waking up in 3.9 seconds. ================================================================================ 2) freeradius radclient - Without CHAP-Challenge echo "User-Name=20M-GPON-HSI(a)ttp.it,CHAP-Password=test " | radclient localhost:1812 auth InternalSecret Sent Access-Request Id 254 from 0.0.0.0:52073 to 127.0.0.1:1812 length 60 Received Access-Accept Id 254 from 127.0.0.1:1812 to 0.0.0.0:0 length 91 (4) Received Access-Request Id 254 from 127.0.0.1:52073 to 127.0.0.1:1812 length 60 (4) User-Name = "20M-GPON-HSI(a)ttp.it" (4) CHAP-Password = 0x569a8ea3bd2e4cb534e96d7b70d83cf014 (4) # Executing section authorize from file /etc/raddb/sites-enabled/default (4) authorize { (4) policy debug-rule { (4) update control { (4) EXPAND %{debug:5} (4) --> 2 (4) Tmp-String-9 = 2 (4) } # update control = noop (4) } # policy debug-rule = noop (4) policy filter_username { (4) if (&User-Name) { (4) if (&User-Name) -> TRUE (4) if (&User-Name) { (4) if (&User-Name =~ / /) { (4) if (&User-Name =~ / /) -> FALSE (4) if (&User-Name =~ /@[^@]*@/ ) { (4) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (4) if (&User-Name =~ /\.\./ ) { (4) if (&User-Name =~ /\.\./ ) -> FALSE (4) if (&User-Name =~ /\.$/) { (4) if (&User-Name =~ /\.$/) -> FALSE (4) if (&User-Name =~ /(a)\./) { (4) if (&User-Name =~ /(a)\./) -> FALSE (4) } # if (&User-Name) = noop (4) } # policy filter_username = noop (4) modsingle[authorize]: calling preprocess (rlm_preprocess) (4) preprocess: hints: Matched DEFAULT at 9 (4) preprocess: ::: FROM 4 TO 4 MAX 8 (4) preprocess: ::: Examining Hint (4) preprocess: ::: APPENDING Hint FROM 0 TO 4 (4) preprocess: ::: Examining Stripped-User-Name (4) preprocess: 1/3 Found: 20M-GPON-HSI (13) (4) preprocess: EXPAND %{1} (4) preprocess: --> 20M-GPON-HSI (4) preprocess: ::: APPENDING Stripped-User-Name FROM 1 TO 4 (4) preprocess: ::: Examining Realm (4) preprocess: 2/3 Found: ttp.it (7) (4) preprocess: EXPAND %{2} (4) preprocess: --> ttp.it (4) preprocess: ::: APPENDING Realm FROM 2 TO 4 (4) preprocess: ::: Examining HPE-ISPVN-Id (4) preprocess: ::: APPENDING HPE-ISPVN-Id FROM 3 TO 4 (4) preprocess: ::: TO in 4 out 4 (4) preprocess: ::: to[0] = User-Name (4) preprocess: ::: to[1] = CHAP-Password (4) preprocess: ::: to[2] = Event-Timestamp (4) preprocess: ::: to[3] = NAS-IP-Address (4) modsingle[authorize]: returned from preprocess (rlm_preprocess) (4) [preprocess] = ok (4) policy nas-info { (4) update control { (4) Cache-Status-Only = yes (4) } # update control = noop (4) modsingle[authorize]: calling cache-nas (rlm_cache) (4) cache-nas: EXPAND %{NAS-IP-Address} (4) cache-nas: --> 127.0.0.1 (4) cache-nas: Mutex acquired (4) cache-nas: No cache entry found for "127.0.0.1" (4) cache-nas: Mutex released (4) modsingle[authorize]: returned from cache-nas (rlm_cache) (4) [cache-nas] = notfound (4) if (notfound) { (4) if (notfound) -> TRUE (4) if (notfound) { (4) update control { (4) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (4) --> 20M-GPON-HSI (4) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (1) (4) EXPAND /var/log/radius/sqllog.sql (4) --> /var/log/radius/sqllog.sql (4) Executing select query: SELECT * FROM DUAL rlm_sql (sql_primary_default): Released connection (1) Need 4 more connections to reach 10 spares rlm_sql (sql_primary_default): Opening additional connection (9), 1 of 26 pending slots used (4) EXPAND %{sql_primary_default:SELECT * FROM DUAL} (4) --> X (4) Tmp-String-0 := X (4) } # update control = noop (4) if (&control:Tmp-String-0 != "") { (4) if (&control:Tmp-String-0 != "") -> TRUE (4) if (&control:Tmp-String-0 != "") { (4) update control { (4) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (4) --> 20M-GPON-HSI (4) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (0) (4) EXPAND /var/log/radius/sqllog.sql (4) --> /var/log/radius/sqllog.sql (4) Executing select query: SELECT VENDOR_ID||'~'||VALUE||'~'||VPDN_VENDOR_CODING_ID FROM NAS a, NAS_TAG b, VPDN_LAC l WHERE A.ID = B.NAS_ID (+) AND B.NAS_TAG_NAME_ID (+) = 1 AND A.ID = L.NAS_ID (+) AND A.IP_ADDR_TXT = '127.0.0.1' (4) SQL query returned no results rlm_sql (sql_primary_default): Released connection (0) (4) EXPAND %{sql_primary_default:SELECT VENDOR_ID||'~'||VALUE||'~'||VPDN_VENDOR_CODING_ID FROM NAS a, NAS_TAG b, VPDN_LAC l WHERE A.ID = B.NAS_ID (+) AND B.NAS_TAG_NAME_ID (+) = 1 AND A.ID = L.NAS_ID (+) AND A.IP_ADDR_TXT = '%{NAS-IP-Address}'} (4) --> (4) Tmp-String-1 := (4) } # update control = noop (4) } # if (&control:Tmp-String-0 != "") = noop (4) ... skipping else: Preceding "if" was taken (4) if (&control:Tmp-String-1 =~ /([0-9]*)~(.*)~([0-9]*)/) { (4) if (&control:Tmp-String-1 =~ /([0-9]*)~(.*)~([0-9]*)/) -> FALSE (4) else { (4) update control { (4) Tmp-Integer-2 := 0 (4) Tmp-String-2 := '' (4) Tmp-Integer-3 := 0 (4) } # update control = noop (4) } # else = noop (4) } # if (notfound) = noop (4) modsingle[authorize]: calling cache-nas (rlm_cache) (4) cache-nas: EXPAND %{NAS-IP-Address} (4) cache-nas: --> 127.0.0.1 (4) cache-nas: Mutex acquired (4) cache-nas: No cache entry found for "127.0.0.1" (4) cache-nas: Creating new cache entry (4) cache-nas: &control:HPE-NAS-VendorId := &control:Tmp-Integer-2 -> 0 (4) cache-nas: &control:HPE-NAS-DNS-Zone := &control:Tmp-String-2 -> '' (4) cache-nas: &control:HPE-NAS-VendorCodingId := &control:Tmp-Integer-3 -> 0 (4) cache-nas: Merging cache entry into request (4) cache-nas: &control:HPE-NAS-VendorId := 0 (4) cache-nas: &control:HPE-NAS-DNS-Zone := "" (4) cache-nas: &control:HPE-NAS-VendorCodingId := 0 (4) cache-nas: ::: FROM 3 TO 6 MAX 9 (4) cache-nas: ::: Examining HPE-NAS-VendorId (4) cache-nas: ::: APPENDING HPE-NAS-VendorId FROM 0 TO 6 (4) cache-nas: ::: Examining HPE-NAS-DNS-Zone (4) cache-nas: ::: APPENDING HPE-NAS-DNS-Zone FROM 1 TO 6 (4) cache-nas: ::: Examining HPE-NAS-VendorCodingId (4) cache-nas: ::: APPENDING HPE-NAS-VendorCodingId FROM 2 TO 6 (4) cache-nas: ::: TO in 6 out 6 (4) cache-nas: ::: to[0] = Tmp-String-9 (4) cache-nas: ::: to[1] = Tmp-String-0 (4) cache-nas: ::: to[2] = Tmp-String-1 (4) cache-nas: ::: to[3] = Tmp-Integer-2 (4) cache-nas: ::: to[4] = Tmp-String-2 (4) cache-nas: ::: to[5] = Tmp-Integer-3 (4) cache-nas: Committed entry, TTL 60 seconds (4) cache-nas: Mutex released (4) modsingle[authorize]: returned from cache-nas (rlm_cache) (4) [cache-nas] = updated (4) } # policy nas-info = updated (4) policy auth-by-callingId { (4) if (&Calling-Station-ID){ (4) if (&Calling-Station-ID) -> FALSE (4) else { (4) update control { (4) HPE-Auth-By-CliId := No (4) } # update control = noop (4) } # else = noop (4) } # policy auth-by-callingId = noop (4) if (&control:HPE-Auth-By-CliId == "Yes") { (4) if (&control:HPE-Auth-By-CliId == "Yes") -> FALSE (4) else { (4) if (&request:Hint == "ROAM") { (4) if (&request:Hint == "ROAM") -> FALSE (4) elsif (&request:Hint == "VPDN") { (4) elsif (&request:Hint == "VPDN") -> FALSE (4) else { (4) if (&request:HPE-ISPVN-Id == 1000912) { (4) if (&request:HPE-ISPVN-Id == 1000912) -> FALSE (4) else { (4) redundant redundant_sql_default { (4) modsingle[authorize]: calling sql_primary_default (rlm_sql) (4) sql_primary_default: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (4) sql_primary_default: --> 20M-GPON-HSI (4) sql_primary_default: SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (7) (4) sql_primary_default: EXPAND SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY id (4) sql_primary_default: --> SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (4) sql_primary_default: Executing select query: SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (4) sql_primary_default: User found in radcheck table (4) sql_primary_default: Conditional check items matched, merging assignment check items (4) sql_primary_default: Cleartext-Password := "test" (4) sql_primary_default: ::: FROM 1 TO 10 MAX 11 (4) sql_primary_default: ::: Examining Cleartext-Password (4) sql_primary_default: ::: APPENDING Cleartext-Password FROM 0 TO 10 (4) sql_primary_default: ::: TO in 10 out 10 (4) sql_primary_default: ::: to[0] = Tmp-String-9 (4) sql_primary_default: ::: to[1] = Tmp-String-0 (4) sql_primary_default: ::: to[2] = Tmp-String-1 (4) sql_primary_default: ::: to[3] = Tmp-Integer-2 (4) sql_primary_default: ::: to[4] = Tmp-String-2 (4) sql_primary_default: ::: to[5] = Tmp-Integer-3 (4) sql_primary_default: ::: to[6] = HPE-NAS-VendorId (4) sql_primary_default: ::: to[7] = HPE-NAS-DNS-Zone (4) sql_primary_default: ::: to[8] = HPE-NAS-VendorCodingId (4) sql_primary_default: ::: to[9] = HPE-Auth-By-CliId (4) sql_primary_default: EXPAND SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,%{&control:HPE-Nas-VendorId}) AND lower(s.username) = '%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY id (4) sql_primary_default: --> SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (4) sql_primary_default: Executing select query: SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (4) sql_primary_default: ... falling-through to group processing (4) sql_primary_default: EXPAND SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY priority (4) sql_primary_default: --> SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY priority (4) sql_primary_default: Executing select query: SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY priority (4) sql_primary_default: User found in the group table (4) sql_primary_default: EXPAND SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = '%{sql_primary_default-SQL-Group}' ORDER BY id (4) sql_primary_default: --> SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (4) sql_primary_default: Executing select query: SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (4) sql_primary_default: Group "RAC x 20M-GPON-HSI": Conditional check items matched (4) sql_primary_default: Group "RAC x 20M-GPON-HSI": Merging assignment check items (4) sql_primary_default: ::: FROM 0 TO 11 MAX 11 (4) sql_primary_default: ::: TO in 11 out 11 (4) sql_primary_default: ::: to[0] = Tmp-String-9 (4) sql_primary_default: ::: to[1] = Tmp-String-0 (4) sql_primary_default: ::: to[2] = Tmp-String-1 (4) sql_primary_default: ::: to[3] = Tmp-Integer-2 (4) sql_primary_default: ::: to[4] = Tmp-String-2 (4) sql_primary_default: ::: to[5] = Tmp-Integer-3 (4) sql_primary_default: ::: to[6] = HPE-NAS-VendorId (4) sql_primary_default: ::: to[7] = HPE-NAS-DNS-Zone (4) sql_primary_default: ::: to[8] = HPE-NAS-VendorCodingId (4) sql_primary_default: ::: to[9] = HPE-Auth-By-CliId (4) sql_primary_default: ::: to[10] = Cleartext-Password (4) sql_primary_default: EXPAND SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,%{&control:HPE-Nas-VendorId}) AND rg.name = '%{sql_primary_default-SQL-Group}' ORDER BY id (4) sql_primary_default: --> SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (4) sql_primary_default: Executing select query: SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (4) sql_primary_default: Group "RAC x 20M-GPON-HSI": Merging reply items (4) sql_primary_default: Acct-Interim-Interval = 21600 (4) sql_primary_default: ::: FROM 1 TO 0 MAX 1 (4) sql_primary_default: ::: Examining Acct-Interim-Interval (4) sql_primary_default: ::: APPENDING Acct-Interim-Interval FROM 0 TO 0 (4) sql_primary_default: ::: TO in 0 out 0 (4) sql_primary_default: ... falling-through to profile processing rlm_sql (sql_primary_default): Released connection (7) (4) modsingle[authorize]: returned from sql_primary_default (rlm_sql) (4) [sql_primary_default] = ok (4) } # redundant redundant_sql_default = ok (4) policy check-block { (4) if (&control:HPE-Block-Subscriber && &control:HPE-Block-Subscriber == "Y") { (4) if (&control:HPE-Block-Subscriber && &control:HPE-Block-Subscriber == "Y") -> FALSE (4) } # policy check-block = ok (4) } # else = ok (4) } # else = ok (4) } # else = ok (4) modsingle[authorize]: calling chap (rlm_chap) (4) chap: &control:Auth-Type := CHAP (4) modsingle[authorize]: returned from chap (rlm_chap) (4) [chap] = ok (4) modsingle[authorize]: calling expiration (rlm_expiration) (4) modsingle[authorize]: returned from expiration (rlm_expiration) (4) [expiration] = noop (4) modsingle[authorize]: calling logintime (rlm_logintime) (4) modsingle[authorize]: returned from logintime (rlm_logintime) (4) [logintime] = noop (4) modsingle[authorize]: calling pap (rlm_pap) (4) pap: WARNING: Auth-Type already set. Not setting to PAP (4) modsingle[authorize]: returned from pap (rlm_pap) (4) [pap] = noop (4) } # authorize = updated (4) Found Auth-Type = CHAP (4) # Executing group from file /etc/raddb/sites-enabled/default (4) Auth-Type CHAP { (4) modsingle[authenticate]: calling chap (rlm_chap) (4) chap: Comparing with "known good" &control:Cleartext-Password value "test" (4) chap: Using challenge from &request:CHAP-Challenge (4) chap: CHAP challenge : ab92e95e73021e400f73f42fbe26221a (4) chap: Client sent : 9a8ea3bd2e4cb534e96d7b70d83cf014 (4) chap: We calculated : 9a8ea3bd2e4cb534e96d7b70d83cf014 (4) chap: CHAP user "20M-GPON-HSI" authenticated successfully (4) modsingle[authenticate]: returned from chap (rlm_chap) (4) [chap] = ok (4) } # Auth-Type CHAP = ok (4) # Executing section post-auth from file /etc/raddb/sites-enabled/default (4) post-auth { (4) policy debug-rule { (4) update control { (4) EXPAND %{debug:5} (4) --> 4 (4) Tmp-String-9 = 4 (4) Refusing to overwrite (use :=) (4) } # update control = noop (4) } # policy debug-rule = noop (4) if (&request:HPE-ISPVN-Id == 1000912) { (4) if (&request:HPE-ISPVN-Id == 1000912) -> FALSE (4) elsif (&request:HPE-ISPVN-Id == 1003334) { (4) elsif (&request:HPE-ISPVN-Id == 1003334) -> FALSE (4) policy insert_hpe_acct_class { (4) update control { (4) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (4) --> 20M-GPON-HSI (4) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (8) (4) EXPAND /var/log/radius/sqllog.sql (4) --> /var/log/radius/sqllog.sql (4) Executing select query: SELECT * FROM DUAL rlm_sql (sql_primary_default): Released connection (8) (4) EXPAND %{sql_primary_default:SELECT * FROM DUAL} (4) --> X (4) Tmp-String-0 := X (4) Overwriting value "X" with "X" (4) } # update control = noop (4) if (&request:Hint == "Access") { (4) if (&request:Hint == "Access") -> TRUE (4) if (&request:Hint == "Access") { (4) if (&control:Tmp-String-0 != "") { (4) if (&control:Tmp-String-0 != "") -> TRUE (4) if (&control:Tmp-String-0 != "") { (4) update reply { (4) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (4) --> 20M-GPON-HSI (4) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (6) (4) EXPAND /var/log/radius/sqllog.sql (4) --> /var/log/radius/sqllog.sql (4) Executing select query: SELECT create_class_attr('Access',1059241,'20M-GPON-HSI','','No','127.0.0.1','','') FROM DUAL rlm_sql (sql_primary_default): Released connection (6) (4) EXPAND %{sql_primary_default:SELECT create_class_attr('%{Hint}',%{HPE-ISPVN-Id},'%{%{Stripped-User-Name}:-%{User-Name}}','%{Calling-Station-ID}','%{&control:HPE-Auth-By-CliId}','%{NAS-IP-Address}','%{HPE-NAS-Desc}','%{HPE-Logon-Time}') FROM DUAL}_AAA: (4) --> A__NA=UNKNOWN_1059241_72924453_1058360_5_2_Y_Y_1753043_0_0_AAA: (4) &Class = 0x415f5f4e413d554e4b4e4f574e5f313035393234315f37323932343435335f313035383336305f355f325f595f595f313735333034335f305f305f4141413a (4) } # update reply = noop (4) } # if (&control:Tmp-String-0 != "") = noop (4) ... skipping else: Preceding "if" was taken (4) } # if (&request:Hint == "Access") = noop (4) ... skipping elsif: Preceding "if" was taken (4) } # policy insert_hpe_acct_class = noop (4) } # post-auth = noop (4) Sent Access-Accept Id 254 from 127.0.0.1:1812 to 127.0.0.1:52073 length 0 (4) Acct-Interim-Interval = 21600 (4) Class = 0x415f5f4e413d554e4b4e4f574e5f313035393234315f37323932343435335f313035383336305f355f325f595f595f313735333034335f305f305f4141413a (4) Finished request ================================================================================ 3) freeradius radclient - CHAP-Challenge under 48 bytes echo "User-Name=20M-GPON-HSI@ttp.it,CHAP-Password=test,CHAP-Challenge=123456789012345678901234 " | radclient localhost:1812 auth InternalSecret Sent Access-Request Id 84 from 0.0.0.0:42359 to 127.0.0.1:1812 length 86 Received Access-Accept Id 84 from 127.0.0.1:1812 to 0.0.0.0:0 length 91 (11) Received Access-Request Id 84 from 127.0.0.1:42359 to 127.0.0.1:1812 length 86 (11) User-Name = "20M-GPON-HSI(a)ttp.it" (11) CHAP-Password = 0xc235ace44d9d6c7deacb03c98def21059a (11) CHAP-Challenge = 0x313233343536373839303132333435363738393031323334 (11) # Executing section authorize from file /etc/raddb/sites-enabled/default (11) authorize { (11) policy debug-rule { (11) update control { (11) EXPAND %{debug:5} (11) --> 2 (11) Tmp-String-9 = 2 (11) } # update control = noop (11) } # policy debug-rule = noop (11) policy filter_username { (11) if (&User-Name) { (11) if (&User-Name) -> TRUE (11) if (&User-Name) { (11) if (&User-Name =~ / /) { (11) if (&User-Name =~ / /) -> FALSE (11) if (&User-Name =~ /@[^@]*@/ ) { (11) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (11) if (&User-Name =~ /\.\./ ) { (11) if (&User-Name =~ /\.\./ ) -> FALSE (11) if (&User-Name =~ /\.$/) { (11) if (&User-Name =~ /\.$/) -> FALSE (11) if (&User-Name =~ /(a)\./) { (11) if (&User-Name =~ /(a)\./) -> FALSE (11) } # if (&User-Name) = noop (11) } # policy filter_username = noop (11) modsingle[authorize]: calling preprocess (rlm_preprocess) (11) preprocess: hints: Matched DEFAULT at 9 (11) preprocess: ::: FROM 4 TO 5 MAX 9 (11) preprocess: ::: Examining Hint (11) preprocess: ::: APPENDING Hint FROM 0 TO 5 (11) preprocess: ::: Examining Stripped-User-Name (11) preprocess: 1/3 Found: 20M-GPON-HSI (13) (11) preprocess: EXPAND %{1} (11) preprocess: --> 20M-GPON-HSI (11) preprocess: ::: APPENDING Stripped-User-Name FROM 1 TO 5 (11) preprocess: ::: Examining Realm (11) preprocess: 2/3 Found: ttp.it (7) (11) preprocess: EXPAND %{2} (11) preprocess: --> ttp.it (11) preprocess: ::: APPENDING Realm FROM 2 TO 5 (11) preprocess: ::: Examining HPE-ISPVN-Id (11) preprocess: ::: APPENDING HPE-ISPVN-Id FROM 3 TO 5 (11) preprocess: ::: TO in 5 out 5 (11) preprocess: ::: to[0] = User-Name (11) preprocess: ::: to[1] = CHAP-Password (11) preprocess: ::: to[2] = CHAP-Challenge (11) preprocess: ::: to[3] = Event-Timestamp (11) preprocess: ::: to[4] = NAS-IP-Address (11) modsingle[authorize]: returned from preprocess (rlm_preprocess) (11) [preprocess] = ok (11) policy nas-info { (11) update control { (11) Cache-Status-Only = yes (11) } # update control = noop (11) modsingle[authorize]: calling cache-nas (rlm_cache) (11) cache-nas: EXPAND %{NAS-IP-Address} (11) cache-nas: --> 127.0.0.1 (11) cache-nas: Mutex acquired (11) cache-nas: No cache entry found for "127.0.0.1" (11) cache-nas: Mutex released (11) modsingle[authorize]: returned from cache-nas (rlm_cache) (11) [cache-nas] = notfound (11) if (notfound) { (11) if (notfound) -> TRUE (11) if (notfound) { (11) update control { (11) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (11) --> 20M-GPON-HSI (11) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (6) (11) EXPAND /var/log/radius/sqllog.sql (11) --> /var/log/radius/sqllog.sql (11) Executing select query: SELECT * FROM DUAL rlm_sql (sql_primary_default): Released connection (6) Need 4 more connections to reach 10 spares rlm_sql (sql_primary_default): Opening additional connection (16), 1 of 26 pending slots used (11) EXPAND %{sql_primary_default:SELECT * FROM DUAL} (11) --> X (11) Tmp-String-0 := X (11) } # update control = noop (11) if (&control:Tmp-String-0 != "") { (11) if (&control:Tmp-String-0 != "") -> TRUE (11) if (&control:Tmp-String-0 != "") { (11) update control { (11) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (11) --> 20M-GPON-HSI (11) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (12) (11) EXPAND /var/log/radius/sqllog.sql (11) --> /var/log/radius/sqllog.sql (11) Executing select query: SELECT VENDOR_ID||'~'||VALUE||'~'||VPDN_VENDOR_CODING_ID FROM NAS a, NAS_TAG b, VPDN_LAC l WHERE A.ID = B.NAS_ID (+) AND B.NAS_TAG_NAME_ID (+) = 1 AND A.ID = L.NAS_ID (+) AND A.IP_ADDR_TXT = '127.0.0.1' (11) SQL query returned no results rlm_sql (sql_primary_default): Released connection (12) (11) EXPAND %{sql_primary_default:SELECT VENDOR_ID||'~'||VALUE||'~'||VPDN_VENDOR_CODING_ID FROM NAS a, NAS_TAG b, VPDN_LAC l WHERE A.ID = B.NAS_ID (+) AND B.NAS_TAG_NAME_ID (+) = 1 AND A.ID = L.NAS_ID (+) AND A.IP_ADDR_TXT = '%{NAS-IP-Address}'} (11) --> (11) Tmp-String-1 := (11) } # update control = noop (11) } # if (&control:Tmp-String-0 != "") = noop (11) ... skipping else: Preceding "if" was taken (11) if (&control:Tmp-String-1 =~ /([0-9]*)~(.*)~([0-9]*)/) { (11) if (&control:Tmp-String-1 =~ /([0-9]*)~(.*)~([0-9]*)/) -> FALSE (11) else { (11) update control { (11) Tmp-Integer-2 := 0 (11) Tmp-String-2 := '' (11) Tmp-Integer-3 := 0 (11) } # update control = noop (11) } # else = noop (11) } # if (notfound) = noop (11) modsingle[authorize]: calling cache-nas (rlm_cache) (11) cache-nas: EXPAND %{NAS-IP-Address} (11) cache-nas: --> 127.0.0.1 (11) cache-nas: Mutex acquired (11) cache-nas: No cache entry found for "127.0.0.1" (11) cache-nas: Creating new cache entry (11) cache-nas: &control:HPE-NAS-VendorId := &control:Tmp-Integer-2 -> 0 (11) cache-nas: &control:HPE-NAS-DNS-Zone := &control:Tmp-String-2 -> '' (11) cache-nas: &control:HPE-NAS-VendorCodingId := &control:Tmp-Integer-3 -> 0 (11) cache-nas: Merging cache entry into request (11) cache-nas: &control:HPE-NAS-VendorId := 0 (11) cache-nas: &control:HPE-NAS-DNS-Zone := "" (11) cache-nas: &control:HPE-NAS-VendorCodingId := 0 (11) cache-nas: ::: FROM 3 TO 6 MAX 9 (11) cache-nas: ::: Examining HPE-NAS-VendorId (11) cache-nas: ::: APPENDING HPE-NAS-VendorId FROM 0 TO 6 (11) cache-nas: ::: Examining HPE-NAS-DNS-Zone (11) cache-nas: ::: APPENDING HPE-NAS-DNS-Zone FROM 1 TO 6 (11) cache-nas: ::: Examining HPE-NAS-VendorCodingId (11) cache-nas: ::: APPENDING HPE-NAS-VendorCodingId FROM 2 TO 6 (11) cache-nas: ::: TO in 6 out 6 (11) cache-nas: ::: to[0] = Tmp-String-9 (11) cache-nas: ::: to[1] = Tmp-String-0 (11) cache-nas: ::: to[2] = Tmp-String-1 (11) cache-nas: ::: to[3] = Tmp-Integer-2 (11) cache-nas: ::: to[4] = Tmp-String-2 (11) cache-nas: ::: to[5] = Tmp-Integer-3 (11) cache-nas: Committed entry, TTL 60 seconds (11) cache-nas: Mutex released (11) modsingle[authorize]: returned from cache-nas (rlm_cache) (11) [cache-nas] = updated (11) } # policy nas-info = updated (11) policy auth-by-callingId { (11) if (&Calling-Station-ID){ (11) if (&Calling-Station-ID) -> FALSE (11) else { (11) update control { (11) HPE-Auth-By-CliId := No (11) } # update control = noop (11) } # else = noop (11) } # policy auth-by-callingId = noop (11) if (&control:HPE-Auth-By-CliId == "Yes") { (11) if (&control:HPE-Auth-By-CliId == "Yes") -> FALSE (11) else { (11) if (&request:Hint == "ROAM") { (11) if (&request:Hint == "ROAM") -> FALSE (11) elsif (&request:Hint == "VPDN") { (11) elsif (&request:Hint == "VPDN") -> FALSE (11) else { (11) if (&request:HPE-ISPVN-Id == 1000912) { (11) if (&request:HPE-ISPVN-Id == 1000912) -> FALSE (11) else { (11) redundant redundant_sql_default { (11) modsingle[authorize]: calling sql_primary_default (rlm_sql) (11) sql_primary_default: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (11) sql_primary_default: --> 20M-GPON-HSI (11) sql_primary_default: SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (14) (11) sql_primary_default: EXPAND SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY id (11) sql_primary_default: --> SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (11) sql_primary_default: Executing select query: SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (11) sql_primary_default: User found in radcheck table (11) sql_primary_default: Conditional check items matched, merging assignment check items (11) sql_primary_default: Cleartext-Password := "test" (11) sql_primary_default: ::: FROM 1 TO 10 MAX 11 (11) sql_primary_default: ::: Examining Cleartext-Password (11) sql_primary_default: ::: APPENDING Cleartext-Password FROM 0 TO 10 (11) sql_primary_default: ::: TO in 10 out 10 (11) sql_primary_default: ::: to[0] = Tmp-String-9 (11) sql_primary_default: ::: to[1] = Tmp-String-0 (11) sql_primary_default: ::: to[2] = Tmp-String-1 (11) sql_primary_default: ::: to[3] = Tmp-Integer-2 (11) sql_primary_default: ::: to[4] = Tmp-String-2 (11) sql_primary_default: ::: to[5] = Tmp-Integer-3 (11) sql_primary_default: ::: to[6] = HPE-NAS-VendorId (11) sql_primary_default: ::: to[7] = HPE-NAS-DNS-Zone (11) sql_primary_default: ::: to[8] = HPE-NAS-VendorCodingId (11) sql_primary_default: ::: to[9] = HPE-Auth-By-CliId (11) sql_primary_default: EXPAND SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,%{&control:HPE-Nas-VendorId}) AND lower(s.username) = '%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY id (11) sql_primary_default: --> SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (11) sql_primary_default: Executing select query: SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (11) sql_primary_default: ... falling-through to group processing (11) sql_primary_default: EXPAND SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY priority (11) sql_primary_default: --> SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY priority (11) sql_primary_default: Executing select query: SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY priority (11) sql_primary_default: User found in the group table (11) sql_primary_default: EXPAND SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = '%{sql_primary_default-SQL-Group}' ORDER BY id (11) sql_primary_default: --> SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (11) sql_primary_default: Executing select query: SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (11) sql_primary_default: Group "RAC x 20M-GPON-HSI": Conditional check items matched (11) sql_primary_default: Group "RAC x 20M-GPON-HSI": Merging assignment check items (11) sql_primary_default: ::: FROM 0 TO 11 MAX 11 (11) sql_primary_default: ::: TO in 11 out 11 (11) sql_primary_default: ::: to[0] = Tmp-String-9 (11) sql_primary_default: ::: to[1] = Tmp-String-0 (11) sql_primary_default: ::: to[2] = Tmp-String-1 (11) sql_primary_default: ::: to[3] = Tmp-Integer-2 (11) sql_primary_default: ::: to[4] = Tmp-String-2 (11) sql_primary_default: ::: to[5] = Tmp-Integer-3 (11) sql_primary_default: ::: to[6] = HPE-NAS-VendorId (11) sql_primary_default: ::: to[7] = HPE-NAS-DNS-Zone (11) sql_primary_default: ::: to[8] = HPE-NAS-VendorCodingId (11) sql_primary_default: ::: to[9] = HPE-Auth-By-CliId (11) sql_primary_default: ::: to[10] = Cleartext-Password (11) sql_primary_default: EXPAND SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,%{&control:HPE-Nas-VendorId}) AND rg.name = '%{sql_primary_default-SQL-Group}' ORDER BY id (11) sql_primary_default: --> SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (11) sql_primary_default: Executing select query: SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (11) sql_primary_default: Group "RAC x 20M-GPON-HSI": Merging reply items (11) sql_primary_default: Acct-Interim-Interval = 21600 (11) sql_primary_default: ::: FROM 1 TO 0 MAX 1 (11) sql_primary_default: ::: Examining Acct-Interim-Interval (11) sql_primary_default: ::: APPENDING Acct-Interim-Interval FROM 0 TO 0 (11) sql_primary_default: ::: TO in 0 out 0 (11) sql_primary_default: ... falling-through to profile processing rlm_sql (sql_primary_default): Released connection (14) (11) modsingle[authorize]: returned from sql_primary_default (rlm_sql) (11) [sql_primary_default] = ok (11) } # redundant redundant_sql_default = ok (11) policy check-block { (11) if (&control:HPE-Block-Subscriber && &control:HPE-Block-Subscriber == "Y") { (11) if (&control:HPE-Block-Subscriber && &control:HPE-Block-Subscriber == "Y") -> FALSE (11) } # policy check-block = ok (11) } # else = ok (11) } # else = ok (11) } # else = ok (11) modsingle[authorize]: calling chap (rlm_chap) (11) chap: &control:Auth-Type := CHAP (11) modsingle[authorize]: returned from chap (rlm_chap) (11) [chap] = ok (11) modsingle[authorize]: calling expiration (rlm_expiration) (11) modsingle[authorize]: returned from expiration (rlm_expiration) (11) [expiration] = noop (11) modsingle[authorize]: calling logintime (rlm_logintime) (11) modsingle[authorize]: returned from logintime (rlm_logintime) (11) [logintime] = noop (11) modsingle[authorize]: calling pap (rlm_pap) (11) pap: WARNING: Auth-Type already set. Not setting to PAP (11) modsingle[authorize]: returned from pap (rlm_pap) (11) [pap] = noop (11) } # authorize = updated (11) Found Auth-Type = CHAP (11) # Executing group from file /etc/raddb/sites-enabled/default (11) Auth-Type CHAP { (11) modsingle[authenticate]: calling chap (rlm_chap) (11) chap: Comparing with "known good" &control:Cleartext-Password value "test" (11) chap: Using challenge from &request:CHAP-Challenge (11) chap: CHAP challenge : 313233343536373839303132333435363738393031323334 (11) chap: Client sent : 35ace44d9d6c7deacb03c98def21059a (11) chap: We calculated : 35ace44d9d6c7deacb03c98def21059a (11) chap: CHAP user "20M-GPON-HSI" authenticated successfully (11) modsingle[authenticate]: returned from chap (rlm_chap) (11) [chap] = ok (11) } # Auth-Type CHAP = ok (11) # Executing section post-auth from file /etc/raddb/sites-enabled/default (11) post-auth { (11) policy debug-rule { (11) update control { (11) EXPAND %{debug:5} (11) --> 4 (11) Tmp-String-9 = 4 (11) Refusing to overwrite (use :=) (11) } # update control = noop (11) } # policy debug-rule = noop (11) if (&request:HPE-ISPVN-Id == 1000912) { (11) if (&request:HPE-ISPVN-Id == 1000912) -> FALSE (11) elsif (&request:HPE-ISPVN-Id == 1003334) { (11) elsif (&request:HPE-ISPVN-Id == 1003334) -> FALSE (11) policy insert_hpe_acct_class { (11) update control { (11) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (11) --> 20M-GPON-HSI (11) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (15) (11) EXPAND /var/log/radius/sqllog.sql (11) --> /var/log/radius/sqllog.sql (11) Executing select query: SELECT * FROM DUAL rlm_sql (sql_primary_default): Released connection (15) (11) EXPAND %{sql_primary_default:SELECT * FROM DUAL} (11) --> X (11) Tmp-String-0 := X (11) Overwriting value "X" with "X" (11) } # update control = noop (11) if (&request:Hint == "Access") { (11) if (&request:Hint == "Access") -> TRUE (11) if (&request:Hint == "Access") { (11) if (&control:Tmp-String-0 != "") { (11) if (&control:Tmp-String-0 != "") -> TRUE (11) if (&control:Tmp-String-0 != "") { (11) update reply { (11) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (11) --> 20M-GPON-HSI (11) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (13) (11) EXPAND /var/log/radius/sqllog.sql (11) --> /var/log/radius/sqllog.sql (11) Executing select query: SELECT create_class_attr('Access',1059241,'20M-GPON-HSI','','No','127.0.0.1','','') FROM DUAL rlm_sql (sql_primary_default): Released connection (13) (11) EXPAND %{sql_primary_default:SELECT create_class_attr('%{Hint}',%{HPE-ISPVN-Id},'%{%{Stripped-User-Name}:-%{User-Name}}','%{Calling-Station-ID}','%{&control:HPE-Auth-By-CliId}','%{NAS-IP-Address}','%{HPE-NAS-Desc}','%{HPE-Logon-Time}') FROM DUAL}_AAA: (11) --> A__NA=UNKNOWN_1059241_72924453_1058360_5_2_Y_Y_1753043_0_0_AAA: (11) &Class = 0x415f5f4e413d554e4b4e4f574e5f313035393234315f37323932343435335f313035383336305f355f325f595f595f313735333034335f305f305f4141413a (11) } # update reply = noop (11) } # if (&control:Tmp-String-0 != "") = noop (11) ... skipping else: Preceding "if" was taken (11) } # if (&request:Hint == "Access") = noop (11) ... skipping elsif: Preceding "if" was taken (11) } # policy insert_hpe_acct_class = noop (11) } # post-auth = noop (11) Sent Access-Accept Id 84 from 127.0.0.1:1812 to 127.0.0.1:42359 length 0 (11) Acct-Interim-Interval = 21600 (11) Class = 0x415f5f4e413d554e4b4e4f574e5f313035393234315f37323932343435335f313035383336305f355f325f595f595f313735333034335f305f305f4141413a (11) Finished request ================================================================================ 4) freeradius radclient - CHAP-Challenge over 48 bytes echo "User-Name=20M-GPON-HSI@ttp.it,CHAP-Password=test,CHAP-Challenge=1234567890123456789012345 " | radclient localhost:1812 auth InternalSecret Sent Access-Request Id 42 from 0.0.0.0:51748 to 127.0.0.1:1812 length 87 Received Access-Reject Id 42 from 127.0.0.1:1812 to 0.0.0.0:0 length 55 (0) -: Expected Access-Accept got Access-Reject (15) Received Access-Request Id 42 from 127.0.0.1:51748 to 127.0.0.1:1812 length 87 (15) User-Name = "20M-GPON-HSI(a)ttp.it" (15) CHAP-Password = 0x1eaa65c23ab25863470c8fed85eb60c000 (15) CHAP-Challenge = 0x31323334353637383930313233343536373839303132333435 (15) # Executing section authorize from file /etc/raddb/sites-enabled/default (15) authorize { (15) policy debug-rule { (15) update control { (15) EXPAND %{debug:5} (15) --> 2 (15) Tmp-String-9 = 2 (15) } # update control = noop (15) } # policy debug-rule = noop (15) policy filter_username { (15) if (&User-Name) { (15) if (&User-Name) -> TRUE (15) if (&User-Name) { (15) if (&User-Name =~ / /) { (15) if (&User-Name =~ / /) -> FALSE (15) if (&User-Name =~ /@[^@]*@/ ) { (15) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (15) if (&User-Name =~ /\.\./ ) { (15) if (&User-Name =~ /\.\./ ) -> FALSE (15) if (&User-Name =~ /\.$/) { (15) if (&User-Name =~ /\.$/) -> FALSE (15) if (&User-Name =~ /(a)\./) { (15) if (&User-Name =~ /(a)\./) -> FALSE (15) } # if (&User-Name) = noop (15) } # policy filter_username = noop (15) modsingle[authorize]: calling preprocess (rlm_preprocess) (15) preprocess: hints: Matched DEFAULT at 9 (15) preprocess: ::: FROM 4 TO 5 MAX 9 (15) preprocess: ::: Examining Hint (15) preprocess: ::: APPENDING Hint FROM 0 TO 5 (15) preprocess: ::: Examining Stripped-User-Name (15) preprocess: 1/3 Found: 20M-GPON-HSI (13) (15) preprocess: EXPAND %{1} (15) preprocess: --> 20M-GPON-HSI (15) preprocess: ::: APPENDING Stripped-User-Name FROM 1 TO 5 (15) preprocess: ::: Examining Realm (15) preprocess: 2/3 Found: ttp.it (7) (15) preprocess: EXPAND %{2} (15) preprocess: --> ttp.it (15) preprocess: ::: APPENDING Realm FROM 2 TO 5 (15) preprocess: ::: Examining HPE-ISPVN-Id (15) preprocess: ::: APPENDING HPE-ISPVN-Id FROM 3 TO 5 (15) preprocess: ::: TO in 5 out 5 (15) preprocess: ::: to[0] = User-Name (15) preprocess: ::: to[1] = CHAP-Password (15) preprocess: ::: to[2] = CHAP-Challenge (15) preprocess: ::: to[3] = Event-Timestamp (15) preprocess: ::: to[4] = NAS-IP-Address (15) modsingle[authorize]: returned from preprocess (rlm_preprocess) (15) [preprocess] = ok (15) policy nas-info { (15) update control { (15) Cache-Status-Only = yes (15) } # update control = noop (15) modsingle[authorize]: calling cache-nas (rlm_cache) (15) cache-nas: EXPAND %{NAS-IP-Address} (15) cache-nas: --> 127.0.0.1 (15) cache-nas: Mutex acquired (15) cache-nas: No cache entry found for "127.0.0.1" (15) cache-nas: Mutex released (15) modsingle[authorize]: returned from cache-nas (rlm_cache) (15) [cache-nas] = notfound (15) if (notfound) { (15) if (notfound) -> TRUE (15) if (notfound) { (15) update control { (15) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (15) --> 20M-GPON-HSI (15) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (12) (15) EXPAND /var/log/radius/sqllog.sql (15) --> /var/log/radius/sqllog.sql (15) Executing select query: SELECT * FROM DUAL rlm_sql (sql_primary_default): Released connection (12) (15) EXPAND %{sql_primary_default:SELECT * FROM DUAL} (15) --> X (15) Tmp-String-0 := X (15) } # update control = noop (15) if (&control:Tmp-String-0 != "") { (15) if (&control:Tmp-String-0 != "") -> TRUE (15) if (&control:Tmp-String-0 != "") { (15) update control { (15) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (15) --> 20M-GPON-HSI (15) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (14) (15) EXPAND /var/log/radius/sqllog.sql (15) --> /var/log/radius/sqllog.sql (15) Executing select query: SELECT VENDOR_ID||'~'||VALUE||'~'||VPDN_VENDOR_CODING_ID FROM NAS a, NAS_TAG b, VPDN_LAC l WHERE A.ID = B.NAS_ID (+) AND B.NAS_TAG_NAME_ID (+) = 1 AND A.ID = L.NAS_ID (+) AND A.IP_ADDR_TXT = '127.0.0.1' (15) SQL query returned no results rlm_sql (sql_primary_default): Released connection (14) (15) EXPAND %{sql_primary_default:SELECT VENDOR_ID||'~'||VALUE||'~'||VPDN_VENDOR_CODING_ID FROM NAS a, NAS_TAG b, VPDN_LAC l WHERE A.ID = B.NAS_ID (+) AND B.NAS_TAG_NAME_ID (+) = 1 AND A.ID = L.NAS_ID (+) AND A.IP_ADDR_TXT = '%{NAS-IP-Address}'} (15) --> (15) Tmp-String-1 := (15) } # update control = noop (15) } # if (&control:Tmp-String-0 != "") = noop (15) ... skipping else: Preceding "if" was taken (15) if (&control:Tmp-String-1 =~ /([0-9]*)~(.*)~([0-9]*)/) { (15) if (&control:Tmp-String-1 =~ /([0-9]*)~(.*)~([0-9]*)/) -> FALSE (15) else { (15) update control { (15) Tmp-Integer-2 := 0 (15) Tmp-String-2 := '' (15) Tmp-Integer-3 := 0 (15) } # update control = noop (15) } # else = noop (15) } # if (notfound) = noop (15) modsingle[authorize]: calling cache-nas (rlm_cache) (15) cache-nas: EXPAND %{NAS-IP-Address} (15) cache-nas: --> 127.0.0.1 (15) cache-nas: Mutex acquired (15) cache-nas: No cache entry found for "127.0.0.1" (15) cache-nas: Creating new cache entry (15) cache-nas: &control:HPE-NAS-VendorId := &control:Tmp-Integer-2 -> 0 (15) cache-nas: &control:HPE-NAS-DNS-Zone := &control:Tmp-String-2 -> '' (15) cache-nas: &control:HPE-NAS-VendorCodingId := &control:Tmp-Integer-3 -> 0 (15) cache-nas: Merging cache entry into request (15) cache-nas: &control:HPE-NAS-VendorId := 0 (15) cache-nas: &control:HPE-NAS-DNS-Zone := "" (15) cache-nas: &control:HPE-NAS-VendorCodingId := 0 (15) cache-nas: ::: FROM 3 TO 6 MAX 9 (15) cache-nas: ::: Examining HPE-NAS-VendorId (15) cache-nas: ::: APPENDING HPE-NAS-VendorId FROM 0 TO 6 (15) cache-nas: ::: Examining HPE-NAS-DNS-Zone (15) cache-nas: ::: APPENDING HPE-NAS-DNS-Zone FROM 1 TO 6 (15) cache-nas: ::: Examining HPE-NAS-VendorCodingId (15) cache-nas: ::: APPENDING HPE-NAS-VendorCodingId FROM 2 TO 6 (15) cache-nas: ::: TO in 6 out 6 (15) cache-nas: ::: to[0] = Tmp-String-9 (15) cache-nas: ::: to[1] = Tmp-String-0 (15) cache-nas: ::: to[2] = Tmp-String-1 (15) cache-nas: ::: to[3] = Tmp-Integer-2 (15) cache-nas: ::: to[4] = Tmp-String-2 (15) cache-nas: ::: to[5] = Tmp-Integer-3 (15) cache-nas: Committed entry, TTL 60 seconds (15) cache-nas: Mutex released (15) modsingle[authorize]: returned from cache-nas (rlm_cache) (15) [cache-nas] = updated (15) } # policy nas-info = updated (15) policy auth-by-callingId { (15) if (&Calling-Station-ID){ (15) if (&Calling-Station-ID) -> FALSE (15) else { (15) update control { (15) HPE-Auth-By-CliId := No (15) } # update control = noop (15) } # else = noop (15) } # policy auth-by-callingId = noop (15) if (&control:HPE-Auth-By-CliId == "Yes") { (15) if (&control:HPE-Auth-By-CliId == "Yes") -> FALSE (15) else { (15) if (&request:Hint == "ROAM") { (15) if (&request:Hint == "ROAM") -> FALSE (15) elsif (&request:Hint == "VPDN") { (15) elsif (&request:Hint == "VPDN") -> FALSE (15) else { (15) if (&request:HPE-ISPVN-Id == 1000912) { (15) if (&request:HPE-ISPVN-Id == 1000912) -> FALSE (15) else { (15) redundant redundant_sql_default { (15) modsingle[authorize]: calling sql_primary_default (rlm_sql) (15) sql_primary_default: EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (15) sql_primary_default: --> 20M-GPON-HSI (15) sql_primary_default: SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (15) (15) sql_primary_default: EXPAND SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY id (15) sql_primary_default: --> SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (15) sql_primary_default: Executing select query: SELECT rc.id as id, username, ra.name as attribute, value, op FROM RADIUS_CHECK rc, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rc.css_id = s.id AND rc.radius_attr_id = ra.id AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (15) sql_primary_default: User found in radcheck table (15) sql_primary_default: Conditional check items matched, merging assignment check items (15) sql_primary_default: Cleartext-Password := "test" (15) sql_primary_default: ::: FROM 1 TO 10 MAX 11 (15) sql_primary_default: ::: Examining Cleartext-Password (15) sql_primary_default: ::: APPENDING Cleartext-Password FROM 0 TO 10 (15) sql_primary_default: ::: TO in 10 out 10 (15) sql_primary_default: ::: to[0] = Tmp-String-9 (15) sql_primary_default: ::: to[1] = Tmp-String-0 (15) sql_primary_default: ::: to[2] = Tmp-String-1 (15) sql_primary_default: ::: to[3] = Tmp-Integer-2 (15) sql_primary_default: ::: to[4] = Tmp-String-2 (15) sql_primary_default: ::: to[5] = Tmp-Integer-3 (15) sql_primary_default: ::: to[6] = HPE-NAS-VendorId (15) sql_primary_default: ::: to[7] = HPE-NAS-DNS-Zone (15) sql_primary_default: ::: to[8] = HPE-NAS-VendorCodingId (15) sql_primary_default: ::: to[9] = HPE-Auth-By-CliId (15) sql_primary_default: EXPAND SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,%{&control:HPE-Nas-VendorId}) AND lower(s.username) = '%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY id (15) sql_primary_default: --> SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (15) sql_primary_default: Executing select query: SELECT rr.id as id, username, ra.name as attribute, value, op FROM RADIUS_REPLY rr, SUBSCRIPTION s, RADIUS_ATTR ra WHERE rr.css_id = s.id AND rr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND lower(s.username) = '20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY id (15) sql_primary_default: ... falling-through to group processing (15) sql_primary_default: EXPAND SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='%{tolower:%{SQL-User-Name}}' AND s.service_id = %{HPE-ISPVN-Id} ORDER BY priority (15) sql_primary_default: --> SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY priority (15) sql_primary_default: Executing select query: SELECT g.name groupname FROM RADIUS_SUBSCRIPTION_GROUP m, RADIUS_GROUP g, SUBSCRIPTION s WHERE m.group_id = g.id AND m.css_id = s.id AND lower(s.username)='20m-gpon-hsi' AND s.service_id = 1059241 ORDER BY priority (15) sql_primary_default: User found in the group table (15) sql_primary_default: EXPAND SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = '%{sql_primary_default-SQL-Group}' ORDER BY id (15) sql_primary_default: --> SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (15) sql_primary_default: Executing select query: SELECT rgc.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_CHECK rgc, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgc.group_id = rg.id AND rgc.radius_attr_id = ra.id AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (15) sql_primary_default: Group "RAC x 20M-GPON-HSI": Conditional check items matched (15) sql_primary_default: Group "RAC x 20M-GPON-HSI": Merging assignment check items (15) sql_primary_default: ::: FROM 0 TO 11 MAX 11 (15) sql_primary_default: ::: TO in 11 out 11 (15) sql_primary_default: ::: to[0] = Tmp-String-9 (15) sql_primary_default: ::: to[1] = Tmp-String-0 (15) sql_primary_default: ::: to[2] = Tmp-String-1 (15) sql_primary_default: ::: to[3] = Tmp-Integer-2 (15) sql_primary_default: ::: to[4] = Tmp-String-2 (15) sql_primary_default: ::: to[5] = Tmp-Integer-3 (15) sql_primary_default: ::: to[6] = HPE-NAS-VendorId (15) sql_primary_default: ::: to[7] = HPE-NAS-DNS-Zone (15) sql_primary_default: ::: to[8] = HPE-NAS-VendorCodingId (15) sql_primary_default: ::: to[9] = HPE-Auth-By-CliId (15) sql_primary_default: ::: to[10] = Cleartext-Password (15) sql_primary_default: EXPAND SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,%{&control:HPE-Nas-VendorId}) AND rg.name = '%{sql_primary_default-SQL-Group}' ORDER BY id (15) sql_primary_default: --> SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (15) sql_primary_default: Executing select query: SELECT rgr.id as id, rg.name as groupname, ra.name as attribute, value, op FROM RADIUS_GROUP_REPLY rgr, RADIUS_GROUP rg, RADIUS_ATTR ra WHERE rgr.group_id = rg.id AND rgr.radius_attr_id = ra.id AND ra.vendor_id in (0,0) AND rg.name = 'RAC x 20M-GPON-HSI' ORDER BY id (15) sql_primary_default: Group "RAC x 20M-GPON-HSI": Merging reply items (15) sql_primary_default: Acct-Interim-Interval = 21600 (15) sql_primary_default: ::: FROM 1 TO 0 MAX 1 (15) sql_primary_default: ::: Examining Acct-Interim-Interval (15) sql_primary_default: ::: APPENDING Acct-Interim-Interval FROM 0 TO 0 (15) sql_primary_default: ::: TO in 0 out 0 (15) sql_primary_default: ... falling-through to profile processing rlm_sql (sql_primary_default): Released connection (15) (15) modsingle[authorize]: returned from sql_primary_default (rlm_sql) (15) [sql_primary_default] = ok (15) } # redundant redundant_sql_default = ok (15) policy check-block { (15) if (&control:HPE-Block-Subscriber && &control:HPE-Block-Subscriber == "Y") { (15) if (&control:HPE-Block-Subscriber && &control:HPE-Block-Subscriber == "Y") -> FALSE (15) } # policy check-block = ok (15) } # else = ok (15) } # else = ok (15) } # else = ok (15) modsingle[authorize]: calling chap (rlm_chap) (15) chap: &control:Auth-Type := CHAP (15) modsingle[authorize]: returned from chap (rlm_chap) (15) [chap] = ok (15) modsingle[authorize]: calling expiration (rlm_expiration) (15) modsingle[authorize]: returned from expiration (rlm_expiration) (15) [expiration] = noop (15) modsingle[authorize]: calling logintime (rlm_logintime) (15) modsingle[authorize]: returned from logintime (rlm_logintime) (15) [logintime] = noop (15) modsingle[authorize]: calling pap (rlm_pap) (15) pap: WARNING: Auth-Type already set. Not setting to PAP (15) modsingle[authorize]: returned from pap (rlm_pap) (15) [pap] = noop (15) } # authorize = updated (15) Found Auth-Type = CHAP (15) # Executing group from file /etc/raddb/sites-enabled/default (15) Auth-Type CHAP { (15) modsingle[authenticate]: calling chap (rlm_chap) (15) chap: Comparing with "known good" &control:Cleartext-Password value "test" (15) chap: Using challenge from &request:CHAP-Challenge (15) chap: CHAP challenge : 31323334353637383930313233343536373839303132333435 (15) chap: Client sent : aa65c23ab25863470c8fed85eb60c000 (15) chap: We calculated : 3500c23ab25863470c8fed85eb60c000 (15) chap: ERROR: Password comparison failed: password is incorrect (15) modsingle[authenticate]: returned from chap (rlm_chap) (15) [chap] = reject (15) } # Auth-Type CHAP = reject (15) Failed to authenticate the user (15) Using Post-Auth-Type Reject (15) # Executing group from file /etc/raddb/sites-enabled/default (15) Post-Auth-Type REJECT { (15) policy insert_hpe_reply_message { (15) update control { (15) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (15) --> 20M-GPON-HSI (15) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (18) (15) EXPAND /var/log/radius/sqllog.sql (15) --> /var/log/radius/sqllog.sql (15) Executing select query: SELECT * FROM DUAL rlm_sql (sql_primary_default): Released connection (18) (15) EXPAND %{sql_primary_default:SELECT * FROM DUAL} (15) --> X (15) Tmp-String-0 := X (15) Overwriting value "X" with "X" (15) } # update control = noop (15) if (&request:Hint == "Access") { (15) if (&request:Hint == "Access") -> TRUE (15) if (&request:Hint == "Access") { (15) if (&control:Tmp-String-0 != "") { (15) if (&control:Tmp-String-0 != "") -> TRUE (15) if (&control:Tmp-String-0 != "") { (15) update reply { (15) EXPAND %{%{Stripped-User-Name}:-%{%{User-Name}:-DEFAULT}} (15) --> 20M-GPON-HSI (15) SQL-User-Name set to '20M-GPON-HSI' rlm_sql (sql_primary_default): Reserved connection (13) (15) EXPAND /var/log/radius/sqllog.sql (15) --> /var/log/radius/sqllog.sql (15) Executing select query: SELECT create_message_reply('Access',1059241,'20M-GPON-HSI','','No','test','chap: Password comparison failed: password is incorrect') FROM DUAL rlm_sql (sql_primary_default): Released connection (13) (15) EXPAND %{sql_primary_default:SELECT create_message_reply('%{Hint}',%{HPE-ISPVN-Id},'%{%{Stripped-User-Name}:-%{User-Name}}','%{Calling-Station-ID}','%{&control:HPE-Auth-By-CliId}','%{%{&control:Cleartext-Password}:-''}','%{Module-Failure-Message}') FROM DUAL} (15) --> A_1059241_72924453_1058360_test_2 (15) &Reply-Message = A_1059241_72924453_1058360_test_2 (15) } # update reply = noop (15) } # if (&control:Tmp-String-0 != "") = noop (15) ... skipping else: Preceding "if" was taken (15) } # if (&request:Hint == "Access") = noop (15) ... skipping elsif: Preceding "if" was taken (15) ... skipping elsif: Preceding "if" was taken (15) } # policy insert_hpe_reply_message = noop (15) modsingle[post-auth]: calling attr_filter.access_reject (rlm_attr_filter) (15) attr_filter.access_reject: EXPAND %{User-Name} (15) attr_filter.access_reject: --> 20M-GPON-HSI(a)ttp.it (15) attr_filter.access_reject: Matched entry DEFAULT at line 11 (15) attr_filter.access_reject: Attribute "Acct-Interim-Interval" allowed by 0 rules, disallowed by 0 rules (15) attr_filter.access_reject: Reply-Message = "A_1059241_72924453_1058360_test_2" allowed by Reply-Message =* "" (15) attr_filter.access_reject: Attribute "Reply-Message" allowed by 1 rules, disallowed by 0 rules (15) modsingle[post-auth]: returned from attr_filter.access_reject (rlm_attr_filter) (15) [attr_filter.access_reject] = updated (15) } # Post-Auth-Type REJECT = updated (15) Delaying response for 1.000000 seconds Waking up in 0.3 seconds. Waking up in 0.6 seconds. (15) Sending delayed response (15) Sent Access-Reject Id 42 from 127.0.0.1:1812 to 127.0.0.1:51748 length 55 (15) Reply-Message = "A_1059241_72924453_1058360_test_2"

2 3

[Q] radacct data in LDAP?
by Zeus Panchenko 24 Sep '18

24 Sep '18

-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 greetings can radacct data be stored in LDAP? - -- Zeus V. Panchenko jid:zeus@im.ibs.dn.ua IT Dpt., I.B.S. LLC GMT+2 (EET) -----BEGIN PGP SIGNATURE----- iF0EARECAB0WIQQYIXL6FUmD7SUfqoOveOk+D/ejKgUCW6TLzAAKCRCveOk+D/ej KgFwAKDhhjAzdTPBM4/83EXB+14l/93MfwCfXBCMz6bqW/aVKUNkBI4J5G32VyE= =Npmm -----END PGP SIGNATURE-----

3 4

FreeRadius 3.0.15 - some radius requests with realm @mylocal.org wrongly get assigned to Default realm (and then proxied)
by Thorsten Fritsch 24 Sep '18

24 Sep '18

Hi, we're running FreeRadius 3.0.15 and frequently see a proxy errors in the radius.log such as " "ERROR: Failing proxied request for user "dummy.user(a)mylocal.org", due to lack of any response from home server <remote ip> port 1812" The problem as it seems is that for some users (by far not for all - just for a few) who provide the correct suffix @mylocal.org the radius request is still wrongly assigned to the default realm and then proxied to the remote radius server defined in the default realm instead of proxied to the local realm as show in this log: (948091) Tue Sep 18 17:42:20 2018: Debug: suffix: Looking up realm " mylocal.org " for User-Name = "dummy.user(a)mylocal.org " (948090) Tue Sep 18 17:42:20 2018: Debug: eap_peap: Peer indicated complete TLS record size will be 126 bytes (948089) Tue Sep 18 17:42:20 2018: Debug: } # Auth-Type eap = handled (948091) Tue Sep 18 17:42:20 2018: Debug: suffix: Found realm "~.*$" For the other let's say 99% who are providing the very same suffix @ mylocal.org the request is correctly proxied to the local realm (inner tunnel auth processed locally): Debug: suffix: Looking up realm "stud.unibas.ch" for User-Name = " other.user(a)mylocal.org" (946065) Tue Sep 18 17:41:41 2018: Debug: suffix: Found realm "mylocal.org" (946065) Tue Sep 18 17:41:41 2018: Debug: suffix: Adding Realm = " mylocal.org" (946065) Tue Sep 18 17:41:41 2018: Debug: suffix: Authentication realm is LOCAL Interestingly it's again and again the same users are wrongly assigned to the default realm. It looks like a loop but the operator of the remote radius server informed us no requests for @mylocal.org are seen on his side. Thanks, T.C.

3 5

WPA2 Client Authentication using Radius and remote LDAP server
by daada muyiwa 22 Sep '18

22 Sep '18

Hello Guys, I have been trying to set up Freeradius to remotely query an LDAP server when it gets authentication requests from a Wireless LAN Controller. I have been able to test that the Freeradius Server can communicate with the LDAP Server by using a Radtest tool (I get the access-accept reply) but when I try to query the remote LDAP server with requests from the Wireless LAN controller I get the following response: [ldap] No default NMAS login sequence[ldap] looking for check items in directory...[ldap] looking for reply items in directory ...WARNING: No ''known good'' password was found in LDAP. Are you sure that the user has been configured properly? Not sure if its the EAP section of the request that has issues. Your assistance would be highly appreciated. Muyiwa

7 15

converting username to lowercase
by JAHANZAIB SYED 22 Sep '18

22 Sep '18

I am running FreeRADIUS Version 2.2.8 (yes its old) along with Mikrotik Router as NAS (pppoe Server) in radacct table see some user entries with mixed uppercase ,example User1 USER2 in radcheck, the user is defined in lower case. why radacct is putting some user with random lower/uppercase ? How can I force it to use only lowercase for usernames? <http:///>

2 4

Vendor specific attributes in Access-Accept message
by Andrei Abonyo Omondi 21 Sep '18

21 Sep '18

Hello i am trying to send below two Cisco Vendor Specific Attributess in every access-accept message. How do i do this? CiscoAVPair := "subqos-policy-in=S99_IN_POLICING_5Mbps" CiscoAVPair := "subqos-policy-out=S99_OUT_POLICING_5Mbps" I've read that i need to add the VSAs to the dictionary but i cant figure out how to do this. Also how do i set the rule that in every access-accept the VSA are sent? I tried adding them to the user file luck this but no luck… - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -- - - - - - - - - - - - testing Cleartext-Password := "password" CiscoAVPair := "subqos-policy-in=S99_IN_POLICING_5Mbps" CiscoAVPair := "subqos-policy-out=S99_OUT_POLICING_5Mbps" - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -- - - - - - - - - - - - - - - - - - - - - - - This is what I'm getting from radiusd -X output - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - reading pairlist file /etc/raddb/mods-config/files/authorize /etc/raddb/mods-config/files/authorize[90]: Parse error (reply) for entry testing: Expecting operator Failed reading /etc/raddb/mods-config/files/authorize /etc/raddb/mods-enabled/files[9]: Instantiation failed for module "files" - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - If someone could also point me to a good guide or wiki on adding and testing VSAs that would be great Best regards, ________________________________ Note: All emails sent from Safaricom Limited are subject to Safaricom’s Email Terms & Conditions. Please click here to read the policy. http://www.safaricom.co.ke/images/Downloads/Terms_and_Conditions/safaricom_…

2 1

MAC Auth Bypass with default allow
by Mark Muehlbauer 21 Sep '18

21 Sep '18

FreeRadius + MySQL + MAC Authentication Bypass. Scenario: I would like to authenticate all incoming MAC addresses as valid and assign them to VLAN X. Initially I have this working just fine using the users file. Entry in users: DEFAULT Cleartext-Password := "%{User-Name}" Tunnel-Type = VLAN, Tunnel-Medium-Type = IEEE-802, Tunnel-Private-Group-Id = "22" I have MySQL and Radius talking just fine against MAC based authentication. However, I cannot find where the same DEFAULT (allow all MACs) entry should be added to allow this same functionality, but now with a MySQL backend. Thank you any and all in advance for your guidance.

2 1

Mixing pam and ldap
by Douglas Hammond 21 Sep '18

21 Sep '18

using freeradius 3 I have pam working well. I use pam to authenticate against winbind and google-authenticator. I now want to get the user groups from ldap as pam does not pass them along. I have ldap setup only in authorize. I see the user lookup performed and found but no group lookup is done. When is the group lookup performed? Can I mix ldap authorize with pam authenticate like this or is this not going to work? Is the ldap group lookup dependant on the user ldap authentication being successful?

2 2

Problem connecting oracle database with odbc connector
by Saurabh Lahoti 20 Sep '18

20 Sep '18

Hi, While trying to build Freeradius with Oracle & SQL, below error is interpreted with radiusd -X rlm_sql_unixodbc: SQL down 08003 [unixODBC][Driver Manager]Connection not open rlm_sql_unixodbc: Can't allocate the stmt rlm_sql_unixodbc: Socket destructor called, closing socket rlm_sql (sqlADSL): Opening connection failed (0) rlm_sql (sqlADSL): Removing connection pool /usr/app/radius/etc/raddb/mods-enabled/sql[20]: Instantiation failed for module "sqlADSL" Which libraries are missing, could you help please..? ---- *Thanks & Kind Regards,* Saurabh LAHOTI. *Ideas enlighten Innovation**!!!* Please consider the environment before printing this mail..!!

1 0

Fw: Re: WPA2 Client Authentication using Radius and remote LDAP server
by daada muyiwa 20 Sep '18

20 Sep '18

> You don't. It's impossible. You need to follow the Active Directory configuration guide: Deploying RADIUS: Configuring Authentication with Active Directory | | | | Deploying RADIUS: Configuring Authentication with Active Directory Alan DeKok / Design by Andreas Viklund - http://andreasviklund.com/ Deploying RADIUS: The web site of the book | | | This link will not help because the AD is running on a ''separate'' machine. The link shows how to integrate SAMBA and Freeradius on the same machine. I still need help. Also the version of EAP used is PEAP as the request are coming from a Cisco Wireless LAN Controller. On Wednesday, September 19, 2018, 11:41:24 AM GMT+1, Alan DeKok <aland(a)deployingradius.com> wrote: On Sep 19, 2018, at 5:04 AM, daada muyiwa via Freeradius-Users <freeradius-users(a)lists.freeradius.org> wrote: > > Is it an actual LDAP server? Or is it Active Directory? > ''Active directory'' Then it's not a real LDAP server. It's close. but not quite a real LDAP server. >> Allow FreeRADIUS to read the "known good" password from LDAP, and it will Just Work. > > How do I make Freeradius decrypt the EAP request and query the AD with the clear text password in order to authenticate a user. You don't. It's impossible. You need to follow the Active Directory configuration guide: http://deployingradius.com/documents/configuration/active_directory.html Alan DeKok.

3 2