Hello,
I'll be trying the latest Freeradius on Ubuntu 19.10 and I can't seem to be
able to connect.
Can someone please help me? Something seems to have changed.
Many Thanks,
(4) Received Access-Request Id 128 from 127.0.0.1:48822 to 127.0.0.1:1812
length 157
(4) User-Name = "houman"
(4) NAS-Port-Type = Virtual
(4) Service-Type = Framed-User
(4) NAS-Port = 3
(4) NAS-Port-Id = "X-1"
(4) NAS-IP-Address = 172.31.20.12
(4) Called-Station-Id = "172.31.20.12[4500]"
(4) Calling-Station-Id = "185.76.230.248[38823]"
(4) Acct-Session-Id = "1576757594-3"
(4) EAP-Message = 0x0200000b01686f756d616e
(4) NAS-Identifier = "strongSwan"
(4) Message-Authenticator = 0x7e6d9c86703eecf1dc78e34980d98a68
(4) # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/default
(4) authorize {
(4) update control {
(4) EXPAND %l
(4) --> 1576757818
(4) &Current-Timestamp := 1576757818
(4) } # update control = noop
(4) update request {
rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 90
seconds
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (4): Hit idle_timeout, was idle for 90
seconds
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (0): Hit idle_timeout, was idle for 90
seconds
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (5): Hit idle_timeout, was idle for 90
seconds
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (1): Hit idle_timeout, was idle for 90
seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (6): Hit idle_timeout, was idle for 90
seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 90
seconds
rlm_sql (sql): You probably need to lower "min"
rlm_sql_mysql: Socket destructor called, closing socket
rlm_sql (sql): 0 of 0 connections in use. You may need to increase "spare"
rlm_sql (sql): Opening additional connection (7), 1 of 32 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'radius_db' on xx.xxx.xx.xx via
TCP/IP, server version 8.0.18, protocol version 10
rlm_sql (sql): Reserved connection (7)
rlm_sql (sql): Released connection (7)
Need 2 more connections to reach min connections (3)
rlm_sql (sql): Opening additional connection (8), 1 of 31 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'radius_db' on xx.xxx.xx.xx via
TCP/IP, server version 8.0.18, protocol version 10
(4) EXPAND %{User-Name}
(4) --> houman
(4) SQL-User-Name set to 'houman'
rlm_sql (sql): Reserved connection (7)
(4) Executing select query: SELECT UNIX_TIMESTAMP(expires_at) FROM
main_db.`user` WHERE main_db.`user`.username ='houman'
rlm_sql (sql): Released connection (7)
(4) EXPAND %{sql:SELECT UNIX_TIMESTAMP(expires_at) FROM
main_db.`user` WHERE main_db.`user`.username ='%{User-Name}'}
(4) --> 1735689600
(4) &Expires-Timestamp := 1735689600
(4) } # update request = noop
(4) if (&control:Current-Timestamp > &request:Expires-Timestamp) {
(4) if (&control:Current-Timestamp > &request:Expires-Timestamp) ->
FALSE
(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 =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
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) [preprocess] = ok
(4) [chap] = noop
(4) [mschap] = noop
(4) [digest] = noop
(4) suffix: Checking for suffix after "@"
(4) suffix: No '@' in User-Name = "houman", looking up realm NULL
(4) suffix: No such realm "NULL"
(4) [suffix] = noop
(4) eap: Peer sent EAP Response (code 2) ID 0 length 11
(4) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the
rest of authorize
(4) [eap] = ok
(4) } # authorize = ok
(4) Found Auth-Type = eap
(4) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(4) authenticate {
(4) eap: Peer sent packet with method EAP Identity (1)
(4) eap: Calling submodule eap_md5 to process data
(4) eap_md5: Issuing MD5 Challenge
(4) eap: Sending EAP Request (code 1) ID 1 length 22
(4) eap: EAP session adding &reply:State = 0xa17deb22a17ceffe
(4) [eap] = handled
(4) } # authenticate = handled
(4) Using Post-Auth-Type Challenge
(4) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(4) Challenge { ... } # empty sub-section is ignored
(4) Sent Access-Challenge Id 128 from 127.0.0.1:1812 to 127.0.0.1:48822
length 0
(4) EAP-Message = 0x0101001604103a8af45976daf8a272f4e1044cbca4ea
(4) Message-Authenticator = 0x00000000000000000000000000000000
(4) State = 0xa17deb22a17ceffef01faedaf7cde45b
(4) Finished request
Waking up in 4.9 seconds.
(5) Received Access-Request Id 129 from 127.0.0.1:48822 to 127.0.0.1:1812
length 170
(5) User-Name = "houman"
(5) NAS-Port-Type = Virtual
(5) Service-Type = Framed-User
(5) NAS-Port = 3
(5) NAS-Port-Id = "X-1"
(5) NAS-IP-Address = 172.31.20.12
(5) Called-Station-Id = "172.31.20.12[4500]"
(5) Calling-Station-Id = "185.76.230.248[38823]"
(5) Acct-Session-Id = "1576757594-3"
(5) EAP-Message = 0x02010006031a
(5) NAS-Identifier = "strongSwan"
(5) State = 0xa17deb22a17ceffef01faedaf7cde45b
(5) Message-Authenticator = 0x72dac90f5d0d96fc8992a391980d751b
(5) session-state: No cached attributes
(5) # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/default
(5) authorize {
(5) update control {
(5) EXPAND %l
(5) --> 1576757818
(5) &Current-Timestamp := 1576757818
(5) } # update control = noop
(5) update request {
rlm_sql (sql): Reserved connection (8)
rlm_sql (sql): Released connection (8)
(5) EXPAND %{User-Name}
(5) --> houman
(5) SQL-User-Name set to 'houman'
rlm_sql (sql): Reserved connection (7)
(5) Executing select query: SELECT UNIX_TIMESTAMP(expires_at) FROM
main_db.`user` WHERE main_db.`user`.username ='houman'
rlm_sql (sql): Released connection (7)
(5) EXPAND %{sql:SELECT UNIX_TIMESTAMP(expires_at) FROM
main_db.`user` WHERE main_db.`user`.username ='%{User-Name}'}
(5) --> 1735689600
(5) &Expires-Timestamp := 1735689600
(5) } # update request = noop
(5) if (&control:Current-Timestamp > &request:Expires-Timestamp) {
(5) if (&control:Current-Timestamp > &request:Expires-Timestamp) ->
FALSE
(5) policy filter_username {
(5) if (&User-Name) {
(5) if (&User-Name) -> TRUE
(5) if (&User-Name) {
(5) if (&User-Name =~ / /) {
(5) if (&User-Name =~ / /) -> FALSE
(5) if (&User-Name =~ /@[^@]*@/ ) {
(5) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
(5) if (&User-Name =~ /\.\./ ) {
(5) if (&User-Name =~ /\.\./ ) -> FALSE
(5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(5) if (&User-Name =~ /\.$/) {
(5) if (&User-Name =~ /\.$/) -> FALSE
(5) if (&User-Name =~ /(a)\./) {
(5) if (&User-Name =~ /(a)\./) -> FALSE
(5) } # if (&User-Name) = noop
(5) } # policy filter_username = noop
(5) [preprocess] = ok
(5) [chap] = noop
(5) [mschap] = noop
(5) [digest] = noop
(5) suffix: Checking for suffix after "@"
(5) suffix: No '@' in User-Name = "houman", looking up realm NULL
(5) suffix: No such realm "NULL"
(5) [suffix] = noop
(5) eap: Peer sent EAP Response (code 2) ID 1 length 6
(5) eap: No EAP Start, assuming it's an on-going EAP conversation
(5) [eap] = updated
(5) sql: EXPAND %{User-Name}
(5) sql: --> houman
(5) sql: SQL-User-Name set to 'houman'
rlm_sql (sql): Reserved connection (8)
(5) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck
WHERE username = '%{SQL-User-Name}' ORDER BY id
(5) sql: --> SELECT id, username, attribute, value, op FROM radcheck
WHERE username = 'houman' ORDER BY id
(5) sql: Executing select query: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = 'houman' ORDER BY id
(5) sql: User found in radcheck table
(5) sql: Conditional check items matched, merging assignment check items
(5) sql: Cleartext-Password := "houman@lovesyou"
(5) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply
WHERE username = '%{SQL-User-Name}' ORDER BY id
(5) sql: --> SELECT id, username, attribute, value, op FROM radreply
WHERE username = 'houman' ORDER BY id
(5) sql: Executing select query: SELECT id, username, attribute, value, op
FROM radreply WHERE username = 'houman' ORDER BY id
rlm_sql (sql): Reserved connection (7)
rlm_sql (sql): Released connection (7)
(5) sql: EXPAND SELECT groupname FROM radusergroup WHERE username =
'%{SQL-User-Name}' ORDER BY priority
(5) sql: --> SELECT groupname FROM radusergroup WHERE username =
'houman' ORDER BY priority
(5) sql: Executing select query: SELECT groupname FROM radusergroup WHERE
username = 'houman' ORDER BY priority
(5) sql: User not found in any groups
rlm_sql (sql): Released connection (8)
(5) [sql] = ok
(5) [expiration] = noop
(5) [logintime] = noop
(5) pap: WARNING: Auth-Type already set. Not setting to PAP
(5) [pap] = noop
(5) } # authorize = updated
(5) Found Auth-Type = eap
(5) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(5) authenticate {
(5) eap: Expiring EAP session with state 0xa17deb22a17ceffe
(5) eap: Finished EAP session with state 0xa17deb22a17ceffe
(5) eap: Previous EAP request found for state 0xa17deb22a17ceffe, released
from the list
(5) eap: Peer sent packet with method EAP NAK (3)
(5) eap: Found mutually acceptable type MSCHAPv2 (26)
(5) eap: Calling submodule eap_mschapv2 to process data
(5) eap_mschapv2: Issuing Challenge
(5) eap: Sending EAP Request (code 1) ID 2 length 43
(5) eap: EAP session adding &reply:State = 0xa17deb22a07ff1fe
(5) [eap] = handled
(5) } # authenticate = handled
(5) Using Post-Auth-Type Challenge
(5) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(5) Challenge { ... } # empty sub-section is ignored
(5) Sent Access-Challenge Id 129 from 127.0.0.1:1812 to 127.0.0.1:48822
length 0
(5) EAP-Message =
0x0102002b1a01020026109ea8499d23b221fe286e0553b2afd879667265657261646975732d332e302e3139
(5) Message-Authenticator = 0x00000000000000000000000000000000
(5) State = 0xa17deb22a07ff1fef01faedaf7cde45b
(5) Finished request
Waking up in 4.8 seconds.
(6) Received Access-Request Id 130 from 127.0.0.1:48822 to 127.0.0.1:1812
length 229
(6) User-Name = "houman"
(6) NAS-Port-Type = Virtual
(6) Service-Type = Framed-User
(6) NAS-Port = 3
(6) NAS-Port-Id = "X-1"
(6) NAS-IP-Address = 172.31.20.12
(6) Called-Station-Id = "172.31.20.12[4500]"
(6) Calling-Station-Id = "185.76.230.248[38823]"
(6) Acct-Session-Id = "1576757594-3"
(6) EAP-Message =
0x020200411a0202003c316473cdfd9ba7577369c536ec1a3732170000000000000000bdd8d54efc713f6c117e2db89759acfa868367fc3920267200686f756d616e
(6) NAS-Identifier = "strongSwan"
(6) State = 0xa17deb22a07ff1fef01faedaf7cde45b
(6) Message-Authenticator = 0xe167fa7a298b2393526a662c1298ce92
(6) session-state: No cached attributes
(6) # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/default
(6) authorize {
(6) update control {
(6) EXPAND %l
(6) --> 1576757818
(6) &Current-Timestamp := 1576757818
(6) } # update control = noop
(6) update request {
rlm_sql (sql): Reserved connection (8)
rlm_sql (sql): Released connection (8)
(6) EXPAND %{User-Name}
(6) --> houman
(6) SQL-User-Name set to 'houman'
rlm_sql (sql): Reserved connection (7)
(6) Executing select query: SELECT UNIX_TIMESTAMP(expires_at) FROM
main_db.`user` WHERE main_db.`user`.username ='houman'
rlm_sql (sql): Released connection (7)
(6) EXPAND %{sql:SELECT UNIX_TIMESTAMP(expires_at) FROM
main_db.`user` WHERE main_db.`user`.username ='%{User-Name}'}
(6) --> 1735689600
(6) &Expires-Timestamp := 1735689600
(6) } # update request = noop
(6) if (&control:Current-Timestamp > &request:Expires-Timestamp) {
(6) if (&control:Current-Timestamp > &request:Expires-Timestamp) ->
FALSE
(6) policy filter_username {
(6) if (&User-Name) {
(6) if (&User-Name) -> TRUE
(6) if (&User-Name) {
(6) if (&User-Name =~ / /) {
(6) if (&User-Name =~ / /) -> FALSE
(6) if (&User-Name =~ /@[^@]*@/ ) {
(6) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
(6) if (&User-Name =~ /\.\./ ) {
(6) if (&User-Name =~ /\.\./ ) -> FALSE
(6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(6) if (&User-Name =~ /\.$/) {
(6) if (&User-Name =~ /\.$/) -> FALSE
(6) if (&User-Name =~ /(a)\./) {
(6) if (&User-Name =~ /(a)\./) -> FALSE
(6) } # if (&User-Name) = noop
(6) } # policy filter_username = noop
(6) [preprocess] = ok
(6) [chap] = noop
(6) [mschap] = noop
(6) [digest] = noop
(6) suffix: Checking for suffix after "@"
(6) suffix: No '@' in User-Name = "houman", looking up realm NULL
(6) suffix: No such realm "NULL"
(6) [suffix] = noop
(6) eap: Peer sent EAP Response (code 2) ID 2 length 65
(6) eap: No EAP Start, assuming it's an on-going EAP conversation
(6) [eap] = updated
(6) sql: EXPAND %{User-Name}
(6) sql: --> houman
(6) sql: SQL-User-Name set to 'houman'
rlm_sql (sql): Reserved connection (8)
(6) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck
WHERE username = '%{SQL-User-Name}' ORDER BY id
(6) sql: --> SELECT id, username, attribute, value, op FROM radcheck
WHERE username = 'houman' ORDER BY id
(6) sql: Executing select query: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = 'houman' ORDER BY id
(6) sql: User found in radcheck table
(6) sql: Conditional check items matched, merging assignment check items
(6) sql: Cleartext-Password := "houman@lovesyou"
(6) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply
WHERE username = '%{SQL-User-Name}' ORDER BY id
(6) sql: --> SELECT id, username, attribute, value, op FROM radreply
WHERE username = 'houman' ORDER BY id
(6) sql: Executing select query: SELECT id, username, attribute, value, op
FROM radreply WHERE username = 'houman' ORDER BY id
rlm_sql (sql): Reserved connection (7)
rlm_sql (sql): Released connection (7)
(6) sql: EXPAND SELECT groupname FROM radusergroup WHERE username =
'%{SQL-User-Name}' ORDER BY priority
(6) sql: --> SELECT groupname FROM radusergroup WHERE username =
'houman' ORDER BY priority
(6) sql: Executing select query: SELECT groupname FROM radusergroup WHERE
username = 'houman' ORDER BY priority
(6) sql: User not found in any groups
rlm_sql (sql): Released connection (8)
(6) [sql] = ok
(6) [expiration] = noop
(6) [logintime] = noop
(6) pap: WARNING: Auth-Type already set. Not setting to PAP
(6) [pap] = noop
(6) } # authorize = updated
(6) Found Auth-Type = eap
(6) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(6) authenticate {
(6) eap: Expiring EAP session with state 0xa17deb22a07ff1fe
(6) eap: Finished EAP session with state 0xa17deb22a07ff1fe
(6) eap: Previous EAP request found for state 0xa17deb22a07ff1fe, released
from the list
(6) eap: Peer sent packet with method EAP MSCHAPv2 (26)
(6) eap: Calling submodule eap_mschapv2 to process data
(6) eap_mschapv2: # Executing group from file
/etc/freeradius/3.0/sites-enabled/default
(6) eap_mschapv2: authenticate {
(6) mschap: Found Cleartext-Password, hashing to create NT-Password
(6) mschap: Found Cleartext-Password, hashing to create LM-Password
(6) mschap: Creating challenge hash with username: houman
(6) mschap: Client is using MS-CHAPv2
(6) mschap: Adding MS-CHAPv2 MPPE keys
(6) eap_mschapv2: [mschap] = ok
(6) eap_mschapv2: } # authenticate = ok
(6) eap_mschapv2: MSCHAP Success
(6) eap: Sending EAP Request (code 1) ID 3 length 51
(6) eap: EAP session adding &reply:State = 0xa17deb22a37ef1fe
(6) [eap] = handled
(6) } # authenticate = handled
(6) Using Post-Auth-Type Challenge
(6) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(6) Challenge { ... } # empty sub-section is ignored
(6) Sent Access-Challenge Id 130 from 127.0.0.1:1812 to 127.0.0.1:48822
length 0
(6) EAP-Message =
0x010300331a0302002e533d33303232453237443943444437313237423132413042323041304536444630314333323741323538
(6) Message-Authenticator = 0x00000000000000000000000000000000
(6) State = 0xa17deb22a37ef1fef01faedaf7cde45b
(6) Finished request
Waking up in 4.7 seconds.
(7) Received Access-Request Id 131 from 127.0.0.1:48822 to 127.0.0.1:1812
length 170
(7) User-Name = "houman"
(7) NAS-Port-Type = Virtual
(7) Service-Type = Framed-User
(7) NAS-Port = 3
(7) NAS-Port-Id = "X-1"
(7) NAS-IP-Address = 172.31.20.12
(7) Called-Station-Id = "172.31.20.12[4500]"
(7) Calling-Station-Id = "185.76.230.248[38823]"
(7) Acct-Session-Id = "1576757594-3"
(7) EAP-Message = 0x020300061a03
(7) NAS-Identifier = "strongSwan"
(7) State = 0xa17deb22a37ef1fef01faedaf7cde45b
(7) Message-Authenticator = 0x23f98c032ec4bbd63d42cd63c25f36f7
(7) session-state: No cached attributes
(7) # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/default
(7) authorize {
(7) update control {
(7) EXPAND %l
(7) --> 1576757818
(7) &Current-Timestamp := 1576757818
(7) } # update control = noop
(7) update request {
rlm_sql (sql): Reserved connection (8)
rlm_sql (sql): Released connection (8)
(7) EXPAND %{User-Name}
(7) --> houman
(7) SQL-User-Name set to 'houman'
rlm_sql (sql): Reserved connection (7)
(7) Executing select query: SELECT UNIX_TIMESTAMP(expires_at) FROM
main_db.`user` WHERE main_db.`user`.username ='houman'
rlm_sql (sql): Released connection (7)
(7) EXPAND %{sql:SELECT UNIX_TIMESTAMP(expires_at) FROM
main_db.`user` WHERE main_db.`user`.username ='%{User-Name}'}
(7) --> 1735689600
(7) &Expires-Timestamp := 1735689600
(7) } # update request = noop
(7) if (&control:Current-Timestamp > &request:Expires-Timestamp) {
(7) if (&control:Current-Timestamp > &request:Expires-Timestamp) ->
FALSE
(7) policy filter_username {
(7) if (&User-Name) {
(7) if (&User-Name) -> TRUE
(7) if (&User-Name) {
(7) if (&User-Name =~ / /) {
(7) if (&User-Name =~ / /) -> FALSE
(7) if (&User-Name =~ /@[^@]*@/ ) {
(7) if (&User-Name =~ /@[^@]*@/ ) -> FALSE
(7) if (&User-Name =~ /\.\./ ) {
(7) if (&User-Name =~ /\.\./ ) -> FALSE
(7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) {
(7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) ->
FALSE
(7) if (&User-Name =~ /\.$/) {
(7) if (&User-Name =~ /\.$/) -> FALSE
(7) if (&User-Name =~ /(a)\./) {
(7) if (&User-Name =~ /(a)\./) -> FALSE
(7) } # if (&User-Name) = noop
(7) } # policy filter_username = noop
(7) [preprocess] = ok
(7) [chap] = noop
(7) [mschap] = noop
(7) [digest] = noop
(7) suffix: Checking for suffix after "@"
(7) suffix: No '@' in User-Name = "houman", looking up realm NULL
(7) suffix: No such realm "NULL"
(7) [suffix] = noop
(7) eap: Peer sent EAP Response (code 2) ID 3 length 6
(7) eap: No EAP Start, assuming it's an on-going EAP conversation
(7) [eap] = updated
(7) sql: EXPAND %{User-Name}
(7) sql: --> houman
(7) sql: SQL-User-Name set to 'houman'
rlm_sql (sql): Reserved connection (8)
(7) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck
WHERE username = '%{SQL-User-Name}' ORDER BY id
(7) sql: --> SELECT id, username, attribute, value, op FROM radcheck
WHERE username = 'houman' ORDER BY id
(7) sql: Executing select query: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = 'houman' ORDER BY id
(7) sql: User found in radcheck table
(7) sql: Conditional check items matched, merging assignment check items
(7) sql: Cleartext-Password := "houman@lovesyou"
(7) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply
WHERE username = '%{SQL-User-Name}' ORDER BY id
(7) sql: --> SELECT id, username, attribute, value, op FROM radreply
WHERE username = 'houman' ORDER BY id
(7) sql: Executing select query: SELECT id, username, attribute, value, op
FROM radreply WHERE username = 'houman' ORDER BY id
rlm_sql (sql): Reserved connection (7)
rlm_sql (sql): Released connection (7)
Need 1 more connections to reach min connections (3)
rlm_sql (sql): Opening additional connection (9), 1 of 30 pending slots used
rlm_sql_mysql: Starting connect to MySQL server
rlm_sql_mysql: Connected to database 'radius_db' on xx.xxx.xx.xx via
TCP/IP, server version 8.0.18, protocol version 10
(7) sql: EXPAND SELECT groupname FROM radusergroup WHERE username =
'%{SQL-User-Name}' ORDER BY priority
(7) sql: --> SELECT groupname FROM radusergroup WHERE username =
'houman' ORDER BY priority
(7) sql: Executing select query: SELECT groupname FROM radusergroup WHERE
username = 'houman' ORDER BY priority
(7) sql: User not found in any groups
rlm_sql (sql): Released connection (8)
(7) [sql] = ok
(7) [expiration] = noop
(7) [logintime] = noop
(7) pap: WARNING: Auth-Type already set. Not setting to PAP
(7) [pap] = noop
(7) } # authorize = updated
(7) Found Auth-Type = eap
(7) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(7) authenticate {
(7) eap: Expiring EAP session with state 0xa17deb22a37ef1fe
(7) eap: Finished EAP session with state 0xa17deb22a37ef1fe
(7) eap: Previous EAP request found for state 0xa17deb22a37ef1fe, released
from the list
(7) eap: Peer sent packet with method EAP MSCHAPv2 (26)
(7) eap: Calling submodule eap_mschapv2 to process data
(7) eap: Sending EAP Success (code 3) ID 3 length 4
(7) eap: Freeing handler
(7) [eap] = ok
(7) } # authenticate = ok
(7) # Executing section post-auth from file
/etc/freeradius/3.0/sites-enabled/default
(7) post-auth {
(7) update reply {
(7) Acct-Interim-Interval = 300
(7) } # update reply = noop
(7) if (session-state:User-Name && reply:User-Name && request:User-Name
&& (reply:User-Name == request:User-Name)) {
(7) if (session-state:User-Name && reply:User-Name && request:User-Name
&& (reply:User-Name == request:User-Name)) -> FALSE
(7) update {
(7) No attributes updated for RHS &session-state:
(7) } # update = noop
(7) policy sql_session_start.post-auth {
(7) policy acct_unique {
(7) update request {
(7) &Tmp-String-9 := "ai:"
(7) } # update request = noop
(7) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&
("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(7) EXPAND %{hex:&Class}
(7) -->
(7) EXPAND ^%{hex:&Tmp-String-9}
(7) --> ^61693a
(7) if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&
("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) -> FALSE
(7) else {
(7) update request {
(7) EXPAND
%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(7) --> 4777c724ef84c2fd714218f9256dac76
(7) &Acct-Unique-Session-Id := 4777c724ef84c2fd714218f9256dac76
(7) } # update request = noop
(7) } # else = noop
(7) } # policy acct_unique = noop
(7) sql: EXPAND
%{tolower:type.%{%{Acct-Status-Type}:-%{Request-Processing-Stage}}.query}
(7) sql: --> type.post-auth.query
(7) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (8)
(7) sql: EXPAND %{User-Name}
(7) sql: --> houman
(7) sql: SQL-User-Name set to 'houman'
(7) sql: EXPAND INSERT INTO radacct (acctsessionid, acctuniqueid, username,
realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime,
acctstoptime, acctsessiontime, acctauthentic, connectinfo_start,
connectinfo_stop,
acctinputoctets, acctoutputoctets, calledstationid, callingstationid,
acctterminatecause, servicetype, framedprotocol, framedipaddress,
framedipv6address, framedipv6prefix, framedinterfaceid, delegatedipv6prefix)
VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}',
'%{SQL-User-Name}', '%{Realm}',
'%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}}',
NULLIF('%{%{NAS-Port-ID}:-%{NAS-Port}}', ''), '%{NAS-Port-Type}',
FROM_UNIXTIME(%{integer:Event-Timestamp}), NULL, NULL, 0, '',
'%{Connect-Info}', NULL, 0, 0, '%{Called-Station-Id}',
'%{Calling-Station-Id}', NULL, '%{Service-Type}', NULL, '', '', '', '', '')
(7) sql: --> INSERT INTO radacct (acctsessionid, acctuniqueid, username,
realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime,
acctstoptime, acctsessiontime, acctauthentic, connectinfo_start,
connectinfo_stop,
acctinputoctets, acctoutputoctets, calledstationid, callingstationid,
acctterminatecause, servicetype, framedprotocol, framedipaddress,
framedipv6address, framedipv6prefix, framedinterfaceid, delegatedipv6prefix)
VALUES('1576757594-3', '4777c724ef84c2fd714218f9256dac76', 'houman', '',
'172.31.20.12', NULLIF('X-1', ''), 'Virtual', FROM_UNIXTIME(1576757818),
NULL, NULL, 0, '', '', NULL, 0, 0, '172.31.20.12=5B4500=5D',
'185.76.230.248=5B38823=5D', NULL, 'Framed-User', NULL, '', '', '', '', '')
(7) sql: Executing query: INSERT INTO radacct (acctsessionid,
acctuniqueid, username,
realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime,
acctstoptime, acctsessiontime, acctauthentic, connectinfo_start,
connectinfo_stop,
acctinputoctets, acctoutputoctets, calledstationid, callingstationid,
acctterminatecause, servicetype, framedprotocol, framedipaddress,
framedipv6address, framedipv6prefix, framedinterfaceid, delegatedipv6prefix)
VALUES('1576757594-3', '4777c724ef84c2fd714218f9256dac76', 'houman', '',
'172.31.20.12', NULLIF('X-1', ''), 'Virtual', FROM_UNIXTIME(1576757818),
NULL, NULL, 0, '', '', NULL, 0, 0, '172.31.20.12=5B4500=5D',
'185.76.230.248=5B38823=5D', NULL, 'Framed-User', NULL, '', '', '', '', '')
(7) sql: ERROR: rlm_sql_mysql: ERROR 1054 (Unknown column
'framedipv6address' in 'field list'): 42S22
(7) sql: SQL query returned: server error
rlm_sql (sql): Released connection (8)
(7) [sql.accounting] = fail
(7) } # policy sql_session_start.post-auth = fail
(7) } # post-auth = fail
(7) Using Post-Auth-Type Reject
(7) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(7) Post-Auth-Type REJECT {
(7) sql: EXPAND .query
(7) sql: --> .query
(7) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (7)
(7) sql: EXPAND %{User-Name}
(7) sql: --> houman
(7) sql: SQL-User-Name set to 'houman'
(7) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate)
VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S')
(7) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate)
VALUES ( 'houman', '', 'Access-Reject', '2019-12-19 12:16:58')
(7) sql: Executing query: INSERT INTO radpostauth (username, pass, reply,
authdate) VALUES ( 'houman', '', 'Access-Reject', '2019-12-19 12:16:58')
(7) sql: SQL query returned: success
(7) sql: 1 record(s) updated
rlm_sql (sql): Released connection (7)
(7) [sql] = ok
(7) attr_filter.access_reject: EXPAND %{User-Name}
(7) attr_filter.access_reject: --> houman
(7) attr_filter.access_reject: Matched entry DEFAULT at line 11
(7) [attr_filter.access_reject] = updated
(7) [eap] = noop
(7) policy remove_reply_message_if_eap {
(7) if (&reply:EAP-Message && &reply:Reply-Message) {
(7) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
(7) else {
(7) [noop] = noop
(7) } # else = noop
(7) } # policy remove_reply_message_if_eap = noop
(7) } # Post-Auth-Type REJECT = updated
(7) Delaying response for 1.000000 seconds
Waking up in 0.1 seconds.
Waking up in 0.8 seconds.
(7) Sending delayed response
(7) Sent Access-Reject Id 131 from 127.0.0.1:1812 to 127.0.0.1:48822 length
44
(7) EAP-Message = 0x03030004
(7) Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.5 seconds.
(4) Cleaning up request packet ID 128 with timestamp +95
Waking up in 0.1 seconds.
(5) Cleaning up request packet ID 129 with timestamp +95
Waking up in 0.1 seconds.
(6) Cleaning up request packet ID 130 with timestamp +95
Waking up in 0.2 seconds.
(7) Cleaning up request packet ID 131 with timestamp +95
Ready to process requests
