freeradius daloradius 身份验证失败
freeradius daloradius authentication failure
我按照本教程为 raspberry pi 安装了 freeradius 和 dalo radius:
http://www.binaryheartbeat.net/2013/12/raspberry-pi-based-freeradius-server.html
我测试了文件身份验证，它工作正常，但在安装 daloradius 并切换到 MySQL 身份验证失败后，原因不明
这是尝试对用户进行身份验证时出现的 freeradius 输出：
rad_recv: Access-Request packet from host 192.168.1.1 port 32779, id=216, length=172
User-Name = "ccc"
State = 0xf9775519ff7f4c9188c14494359a170f
EAP-Message = 0x0208005b190017030100500d2898ca35aa9fa9e4febd8816c9e6deda71960fe5692b7c3d0499f2b5bba6b531483e373e14f8aff517aa081e214edc98e2c8bb22d16a961ecff4f498d20d152535b4d11ace1484b985bd2501ade77b
Service-Type = Framed-User
Framed-MTU = 1420
NAS-IP-Address = 192.168.1.1
Message-Authenticator = 0x49fc781b8a152fbec467b2c1f275a1a1
Tue Dec 29 18:38:47 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Dec 29 18:38:47 2015 : Info: +group authorize {
Tue Dec 29 18:38:47 2015 : Info: ++[preprocess] = ok
Tue Dec 29 18:38:47 2015 : Info: ++[chap] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[mschap] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[digest] = noop
Tue Dec 29 18:38:47 2015 : Info: [suffix] No '@' in User-Name = "ccc", looking up realm NULL
Tue Dec 29 18:38:47 2015 : Info: [suffix] No such realm "NULL"
Tue Dec 29 18:38:47 2015 : Info: ++[suffix] = noop
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP packet type response id 8 length 91
Tue Dec 29 18:38:47 2015 : Info: [eap] Continuing tunnel setup.
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = ok
Tue Dec 29 18:38:47 2015 : Info: +} # group authorize = ok
Tue Dec 29 18:38:47 2015 : Info: Found Auth-Type = EAP
Tue Dec 29 18:38:47 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Dec 29 18:38:47 2015 : Info: +group authenticate {
Tue Dec 29 18:38:47 2015 : Info: [eap] Request found, released from the list
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP/peap
Tue Dec 29 18:38:47 2015 : Info: [eap] processing type peap
Tue Dec 29 18:38:47 2015 : Info: [peap] processing EAP-TLS
Tue Dec 29 18:38:47 2015 : Info: [peap] eaptls_verify returned 7
Tue Dec 29 18:38:47 2015 : Info: [peap] Done initial handshake
Tue Dec 29 18:38:47 2015 : Info: [peap] eaptls_process returned 7
Tue Dec 29 18:38:47 2015 : Info: [peap] EAPTLS_OK
Tue Dec 29 18:38:47 2015 : Info: [peap] Session established. Decoding tunneled attributes.
Tue Dec 29 18:38:47 2015 : Info: [peap] Peap state phase2
Tue Dec 29 18:38:47 2015 : Info: [peap] EAP type mschapv2
Tue Dec 29 18:38:47 2015 : Info: [peap] Got tunneled request
EAP-Message = 0x0208003e1a0208003931461c2f1334a4b7bab38912e9d82dd97b000000000000000070fb7810a938a00d884f17dc01b62eaa7dde9fbb7ab2cf4200636363
server {
Tue Dec 29 18:38:47 2015 : Info: [peap] Setting User-Name to ccc
Sending tunneled request
EAP-Message = 0x0208003e1a0208003931461c2f1334a4b7bab38912e9d82dd97b000000000000000070fb7810a938a00d884f17dc01b62eaa7dde9fbb7ab2cf4200636363
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "ccc"
State = 0x4bb6eef44bbef48a7072f4e023895561
server inner-tunnel {
Tue Dec 29 18:38:47 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Dec 29 18:38:47 2015 : Info: +group authorize {
Tue Dec 29 18:38:47 2015 : Info: ++[chap] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[mschap] = noop
Tue Dec 29 18:38:47 2015 : Info: [suffix] No '@' in User-Name = "ccc", looking up realm NULL
Tue Dec 29 18:38:47 2015 : Info: [suffix] No such realm "NULL"
Tue Dec 29 18:38:47 2015 : Info: ++[suffix] = noop
Tue Dec 29 18:38:47 2015 : Info: ++update control {
Tue Dec 29 18:38:47 2015 : Info: ++} # update control = noop
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP packet type response id 8 length 62
Tue Dec 29 18:38:47 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = updated
Tue Dec 29 18:38:47 2015 : Info: ++[files] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[expiration] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[logintime] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[pap] = noop
Tue Dec 29 18:38:47 2015 : Info: +} # group authorize = updated
Tue Dec 29 18:38:47 2015 : Info: Found Auth-Type = EAP
Tue Dec 29 18:38:47 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Dec 29 18:38:47 2015 : Info: +group authenticate {
Tue Dec 29 18:38:47 2015 : Info: [eap] Request found, released from the list
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP/mschapv2
Tue Dec 29 18:38:47 2015 : Info: [eap] processing type mschapv2
Tue Dec 29 18:38:47 2015 : Info: [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Dec 29 18:38:47 2015 : Info: [mschapv2] +group MS-CHAP {
Tue Dec 29 18:38:47 2015 : Info: [mschap] No Cleartext-Password configured. Cannot create LM-Password.
Tue Dec 29 18:38:47 2015 : Info: [mschap] No Cleartext-Password configured. Cannot create NT-Password.
Tue Dec 29 18:38:47 2015 : Info: [mschap] Creating challenge hash with username: ccc
Tue Dec 29 18:38:47 2015 : Info: [mschap] Client is using MS-CHAPv2 for ccc, we need NT-Password
Tue Dec 29 18:38:47 2015 : Info: [mschap] FAILED: No NT/LM-Password. Cannot perform authentication.
Tue Dec 29 18:38:47 2015 : Info: [mschap] FAILED: MS-CHAP2-Response is incorrect
Tue Dec 29 18:38:47 2015 : Info: ++[mschap] = reject
Tue Dec 29 18:38:47 2015 : Info: +} # group MS-CHAP = reject
Tue Dec 29 18:38:47 2015 : Info: [eap] Freeing handler
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = reject
Tue Dec 29 18:38:47 2015 : Info: +} # group authenticate = reject
Tue Dec 29 18:38:47 2015 : Info: Failed to authenticate the user.
Tue Dec 29 18:38:47 2015 : Info: Using Post-Auth-Type REJECT
Tue Dec 29 18:38:47 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Dec 29 18:38:47 2015 : Info: +group REJECT {
Tue Dec 29 18:38:47 2015 : Info: [attr_filter.access_reject] expand: %{User-Name} -> ccc
Tue Dec 29 18:38:47 2015 : Debug: attr_filter: Matched entry DEFAULT at line 11
Tue Dec 29 18:38:47 2015 : Info: ++[attr_filter.access_reject] = updated
Tue Dec 29 18:38:47 2015 : Info: +} # group REJECT = updated
} # server inner-tunnel
Tue Dec 29 18:38:47 2015 : Info: [peap] Got tunneled reply code 3
MS-CHAP-Error = "0E=691 R=1"
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
Tue Dec 29 18:38:47 2015 : Info: [peap] Got tunneled reply RADIUS code 3
MS-CHAP-Error = "0E=691 R=1"
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
Tue Dec 29 18:38:47 2015 : Info: [peap] Tunneled authentication was rejected.
Tue Dec 29 18:38:47 2015 : Info: [peap] FAILURE
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = handled
Tue Dec 29 18:38:47 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 216 to 192.168.1.1 port 32779
EAP-Message = 0x0109002b190017030100205991bfd8f9e7f70794477d653c848e8b443626b3b935a5b3f049ac7af1534d3e
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xf9775519fe7e4c9188c14494359a170f
Tue Dec 29 18:38:47 2015 : Info: Finished request 7.
Tue Dec 29 18:38:47 2015 : Debug: Going to the next request
Tue Dec 29 18:38:47 2015 : Debug: Waking up in 0.4 seconds.
rad_recv: Access-Request packet from host 192.168.1.1 port 32779, id=217, length=124
User-Name = "ccc"
State = 0xf9775519fe7e4c9188c14494359a170f
EAP-Message = 0x0209002b190017030100202a7f1a72de2970b689e44c005661d1e1e444854af7499ebeb23eabc7bfad7b64
Service-Type = Framed-User
Framed-MTU = 1420
NAS-IP-Address = 192.168.1.1
Message-Authenticator = 0xc9b0d8e268df2d8e4b484725c3efa189
Tue Dec 29 18:38:47 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Dec 29 18:38:47 2015 : Info: +group authorize {
Tue Dec 29 18:38:47 2015 : Info: ++[preprocess] = ok
Tue Dec 29 18:38:47 2015 : Info: ++[chap] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[mschap] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[digest] = noop
Tue Dec 29 18:38:47 2015 : Info: [suffix] No '@' in User-Name = "ccc", looking up realm NULL
Tue Dec 29 18:38:47 2015 : Info: [suffix] No such realm "NULL"
Tue Dec 29 18:38:47 2015 : Info: ++[suffix] = noop
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP packet type response id 9 length 43
Tue Dec 29 18:38:47 2015 : Info: [eap] Continuing tunnel setup.
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = ok
Tue Dec 29 18:38:47 2015 : Info: +} # group authorize = ok
Tue Dec 29 18:38:47 2015 : Info: Found Auth-Type = EAP
Tue Dec 29 18:38:47 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Dec 29 18:38:47 2015 : Info: +group authenticate {
Tue Dec 29 18:38:47 2015 : Info: [eap] Request found, released from the list
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP/peap
Tue Dec 29 18:38:47 2015 : Info: [eap] processing type peap
Tue Dec 29 18:38:47 2015 : Info: [peap] processing EAP-TLS
Tue Dec 29 18:38:47 2015 : Info: [peap] eaptls_verify returned 7
Tue Dec 29 18:38:47 2015 : Info: [peap] Done initial handshake
Tue Dec 29 18:38:47 2015 : Info: [peap] eaptls_process returned 7
Tue Dec 29 18:38:47 2015 : Info: [peap] EAPTLS_OK
Tue Dec 29 18:38:47 2015 : Info: [peap] Session established. Decoding tunneled attributes.
Tue Dec 29 18:38:47 2015 : Info: [peap] Peap state send tlv failure
Tue Dec 29 18:38:47 2015 : Info: [peap] Received EAP-TLV response.
Tue Dec 29 18:38:47 2015 : Info: [peap] The users session was previously rejected: returning reject (again.)
Tue Dec 29 18:38:47 2015 : Info: [peap] *** This means you need to read the PREVIOUS messages in the debug output
Tue Dec 29 18:38:47 2015 : Info: [peap] *** to find out the reason why the user was rejected.
Tue Dec 29 18:38:47 2015 : Info: [peap] *** Look for "reject" or "fail". Those earlier messages will tell you.
Tue Dec 29 18:38:47 2015 : Info: [peap] *** what went wrong, and how to fix the problem.
Tue Dec 29 18:38:47 2015 : Info: [eap] Handler failed in EAP/peap
Tue Dec 29 18:38:47 2015 : Info: [eap] Failed in EAP select
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = invalid
Tue Dec 29 18:38:47 2015 : Info: +} # group authenticate = invalid
Tue Dec 29 18:38:47 2015 : Info: Failed to authenticate the user.
Tue Dec 29 18:38:47 2015 : Info: Using Post-Auth-Type REJECT
Tue Dec 29 18:38:47 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Dec 29 18:38:47 2015 : Info: +group REJECT {
Tue Dec 29 18:38:47 2015 : Info: [sql] expand: %{User-Name} -> ccc
Tue Dec 29 18:38:47 2015 : Info: [sql] sql_set_user escaped user --> 'ccc'
Tue Dec 29 18:38:47 2015 : Info: [sql] expand: %{User-Password} ->
Tue Dec 29 18:38:47 2015 : Info: [sql] ... expanding second conditional
Tue Dec 29 18:38:47 2015 : Info: [sql] expand: %{Chap-Password} ->
Tue Dec 29 18:38:47 2015 : Info: [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ccc', '', 'Access-Reject', '2015-12-29 18:38:47')
Tue Dec 29 18:38:47 2015 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ccc', '', 'Access-Reject', '2015-12-29 18:38:47')
Tue Dec 29 18:38:47 2015 : Debug: rlm_sql (sql): Reserving sql socket id: 29
Tue Dec 29 18:38:47 2015 : Debug: rlm_sql (sql): Released sql socket id: 29
Tue Dec 29 18:38:47 2015 : Info: ++[sql] = ok
Tue Dec 29 18:38:47 2015 : Info: [attr_filter.access_reject] expand: %{User-Name} -> ccc
Tue Dec 29 18:38:47 2015 : Debug: attr_filter: Matched entry DEFAULT at line 11
Tue Dec 29 18:38:47 2015 : Info: ++[attr_filter.access_reject] = updated
Tue Dec 29 18:38:47 2015 : Info: +} # group REJECT = updated
Tue Dec 29 18:38:47 2015 : Info: Delaying reject of request 8 for 1 seconds
Tue Dec 29 18:38:47 2015 : Debug: Going to the next request
Tue Dec 29 18:38:47 2015 : Debug: Waking up in 0.1 seconds.
Tue Dec 29 18:38:47 2015 : Info: Cleaning up request 0 ID 209 with timestamp +11
Tue Dec 29 18:38:47 2015 : Debug: Waking up in 0.3 seconds.
Tue Dec 29 18:38:47 2015 : Info: Cleaning up request 1 ID 210 with timestamp +11
Tue Dec 29 18:38:47 2015 : Debug: Waking up in 0.3 seconds.
Tue Dec 29 18:38:48 2015 : Info: Cleaning up request 2 ID 211 with timestamp +12
Tue Dec 29 18:38:48 2015 : Debug: Waking up in 0.1 seconds.
Tue Dec 29 18:38:48 2015 : Info: Sending delayed reject for request 8
Sending Access-Reject of id 217 to 192.168.1.1 port 32779
EAP-Message = 0x04090004
Message-Authenticator = 0x00000000000000000000000000000000
找到解决方案，
问题是我没有配置 /etc/raddb/sites-available/inner-tunnel 文件来使用 sql
我按照本教程为 raspberry pi 安装了 freeradius 和 dalo radius:
http://www.binaryheartbeat.net/2013/12/raspberry-pi-based-freeradius-server.html
我测试了文件身份验证，它工作正常，但在安装 daloradius 并切换到 MySQL 身份验证失败后，原因不明
这是尝试对用户进行身份验证时出现的 freeradius 输出：
rad_recv: Access-Request packet from host 192.168.1.1 port 32779, id=216, length=172
User-Name = "ccc"
State = 0xf9775519ff7f4c9188c14494359a170f
EAP-Message = 0x0208005b190017030100500d2898ca35aa9fa9e4febd8816c9e6deda71960fe5692b7c3d0499f2b5bba6b531483e373e14f8aff517aa081e214edc98e2c8bb22d16a961ecff4f498d20d152535b4d11ace1484b985bd2501ade77b
Service-Type = Framed-User
Framed-MTU = 1420
NAS-IP-Address = 192.168.1.1
Message-Authenticator = 0x49fc781b8a152fbec467b2c1f275a1a1
Tue Dec 29 18:38:47 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Dec 29 18:38:47 2015 : Info: +group authorize {
Tue Dec 29 18:38:47 2015 : Info: ++[preprocess] = ok
Tue Dec 29 18:38:47 2015 : Info: ++[chap] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[mschap] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[digest] = noop
Tue Dec 29 18:38:47 2015 : Info: [suffix] No '@' in User-Name = "ccc", looking up realm NULL
Tue Dec 29 18:38:47 2015 : Info: [suffix] No such realm "NULL"
Tue Dec 29 18:38:47 2015 : Info: ++[suffix] = noop
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP packet type response id 8 length 91
Tue Dec 29 18:38:47 2015 : Info: [eap] Continuing tunnel setup.
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = ok
Tue Dec 29 18:38:47 2015 : Info: +} # group authorize = ok
Tue Dec 29 18:38:47 2015 : Info: Found Auth-Type = EAP
Tue Dec 29 18:38:47 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Dec 29 18:38:47 2015 : Info: +group authenticate {
Tue Dec 29 18:38:47 2015 : Info: [eap] Request found, released from the list
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP/peap
Tue Dec 29 18:38:47 2015 : Info: [eap] processing type peap
Tue Dec 29 18:38:47 2015 : Info: [peap] processing EAP-TLS
Tue Dec 29 18:38:47 2015 : Info: [peap] eaptls_verify returned 7
Tue Dec 29 18:38:47 2015 : Info: [peap] Done initial handshake
Tue Dec 29 18:38:47 2015 : Info: [peap] eaptls_process returned 7
Tue Dec 29 18:38:47 2015 : Info: [peap] EAPTLS_OK
Tue Dec 29 18:38:47 2015 : Info: [peap] Session established. Decoding tunneled attributes.
Tue Dec 29 18:38:47 2015 : Info: [peap] Peap state phase2
Tue Dec 29 18:38:47 2015 : Info: [peap] EAP type mschapv2
Tue Dec 29 18:38:47 2015 : Info: [peap] Got tunneled request
EAP-Message = 0x0208003e1a0208003931461c2f1334a4b7bab38912e9d82dd97b000000000000000070fb7810a938a00d884f17dc01b62eaa7dde9fbb7ab2cf4200636363
server {
Tue Dec 29 18:38:47 2015 : Info: [peap] Setting User-Name to ccc
Sending tunneled request
EAP-Message = 0x0208003e1a0208003931461c2f1334a4b7bab38912e9d82dd97b000000000000000070fb7810a938a00d884f17dc01b62eaa7dde9fbb7ab2cf4200636363
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "ccc"
State = 0x4bb6eef44bbef48a7072f4e023895561
server inner-tunnel {
Tue Dec 29 18:38:47 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Dec 29 18:38:47 2015 : Info: +group authorize {
Tue Dec 29 18:38:47 2015 : Info: ++[chap] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[mschap] = noop
Tue Dec 29 18:38:47 2015 : Info: [suffix] No '@' in User-Name = "ccc", looking up realm NULL
Tue Dec 29 18:38:47 2015 : Info: [suffix] No such realm "NULL"
Tue Dec 29 18:38:47 2015 : Info: ++[suffix] = noop
Tue Dec 29 18:38:47 2015 : Info: ++update control {
Tue Dec 29 18:38:47 2015 : Info: ++} # update control = noop
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP packet type response id 8 length 62
Tue Dec 29 18:38:47 2015 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = updated
Tue Dec 29 18:38:47 2015 : Info: ++[files] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[expiration] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[logintime] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[pap] = noop
Tue Dec 29 18:38:47 2015 : Info: +} # group authorize = updated
Tue Dec 29 18:38:47 2015 : Info: Found Auth-Type = EAP
Tue Dec 29 18:38:47 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Dec 29 18:38:47 2015 : Info: +group authenticate {
Tue Dec 29 18:38:47 2015 : Info: [eap] Request found, released from the list
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP/mschapv2
Tue Dec 29 18:38:47 2015 : Info: [eap] processing type mschapv2
Tue Dec 29 18:38:47 2015 : Info: [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Dec 29 18:38:47 2015 : Info: [mschapv2] +group MS-CHAP {
Tue Dec 29 18:38:47 2015 : Info: [mschap] No Cleartext-Password configured. Cannot create LM-Password.
Tue Dec 29 18:38:47 2015 : Info: [mschap] No Cleartext-Password configured. Cannot create NT-Password.
Tue Dec 29 18:38:47 2015 : Info: [mschap] Creating challenge hash with username: ccc
Tue Dec 29 18:38:47 2015 : Info: [mschap] Client is using MS-CHAPv2 for ccc, we need NT-Password
Tue Dec 29 18:38:47 2015 : Info: [mschap] FAILED: No NT/LM-Password. Cannot perform authentication.
Tue Dec 29 18:38:47 2015 : Info: [mschap] FAILED: MS-CHAP2-Response is incorrect
Tue Dec 29 18:38:47 2015 : Info: ++[mschap] = reject
Tue Dec 29 18:38:47 2015 : Info: +} # group MS-CHAP = reject
Tue Dec 29 18:38:47 2015 : Info: [eap] Freeing handler
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = reject
Tue Dec 29 18:38:47 2015 : Info: +} # group authenticate = reject
Tue Dec 29 18:38:47 2015 : Info: Failed to authenticate the user.
Tue Dec 29 18:38:47 2015 : Info: Using Post-Auth-Type REJECT
Tue Dec 29 18:38:47 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel
Tue Dec 29 18:38:47 2015 : Info: +group REJECT {
Tue Dec 29 18:38:47 2015 : Info: [attr_filter.access_reject] expand: %{User-Name} -> ccc
Tue Dec 29 18:38:47 2015 : Debug: attr_filter: Matched entry DEFAULT at line 11
Tue Dec 29 18:38:47 2015 : Info: ++[attr_filter.access_reject] = updated
Tue Dec 29 18:38:47 2015 : Info: +} # group REJECT = updated
} # server inner-tunnel
Tue Dec 29 18:38:47 2015 : Info: [peap] Got tunneled reply code 3
MS-CHAP-Error = "0E=691 R=1"
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
Tue Dec 29 18:38:47 2015 : Info: [peap] Got tunneled reply RADIUS code 3
MS-CHAP-Error = "0E=691 R=1"
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
Tue Dec 29 18:38:47 2015 : Info: [peap] Tunneled authentication was rejected.
Tue Dec 29 18:38:47 2015 : Info: [peap] FAILURE
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = handled
Tue Dec 29 18:38:47 2015 : Info: +} # group authenticate = handled
Sending Access-Challenge of id 216 to 192.168.1.1 port 32779
EAP-Message = 0x0109002b190017030100205991bfd8f9e7f70794477d653c848e8b443626b3b935a5b3f049ac7af1534d3e
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xf9775519fe7e4c9188c14494359a170f
Tue Dec 29 18:38:47 2015 : Info: Finished request 7.
Tue Dec 29 18:38:47 2015 : Debug: Going to the next request
Tue Dec 29 18:38:47 2015 : Debug: Waking up in 0.4 seconds.
rad_recv: Access-Request packet from host 192.168.1.1 port 32779, id=217, length=124
User-Name = "ccc"
State = 0xf9775519fe7e4c9188c14494359a170f
EAP-Message = 0x0209002b190017030100202a7f1a72de2970b689e44c005661d1e1e444854af7499ebeb23eabc7bfad7b64
Service-Type = Framed-User
Framed-MTU = 1420
NAS-IP-Address = 192.168.1.1
Message-Authenticator = 0xc9b0d8e268df2d8e4b484725c3efa189
Tue Dec 29 18:38:47 2015 : Info: # Executing section authorize from file /etc/freeradius/sites-enabled/default
Tue Dec 29 18:38:47 2015 : Info: +group authorize {
Tue Dec 29 18:38:47 2015 : Info: ++[preprocess] = ok
Tue Dec 29 18:38:47 2015 : Info: ++[chap] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[mschap] = noop
Tue Dec 29 18:38:47 2015 : Info: ++[digest] = noop
Tue Dec 29 18:38:47 2015 : Info: [suffix] No '@' in User-Name = "ccc", looking up realm NULL
Tue Dec 29 18:38:47 2015 : Info: [suffix] No such realm "NULL"
Tue Dec 29 18:38:47 2015 : Info: ++[suffix] = noop
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP packet type response id 9 length 43
Tue Dec 29 18:38:47 2015 : Info: [eap] Continuing tunnel setup.
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = ok
Tue Dec 29 18:38:47 2015 : Info: +} # group authorize = ok
Tue Dec 29 18:38:47 2015 : Info: Found Auth-Type = EAP
Tue Dec 29 18:38:47 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Dec 29 18:38:47 2015 : Info: +group authenticate {
Tue Dec 29 18:38:47 2015 : Info: [eap] Request found, released from the list
Tue Dec 29 18:38:47 2015 : Info: [eap] EAP/peap
Tue Dec 29 18:38:47 2015 : Info: [eap] processing type peap
Tue Dec 29 18:38:47 2015 : Info: [peap] processing EAP-TLS
Tue Dec 29 18:38:47 2015 : Info: [peap] eaptls_verify returned 7
Tue Dec 29 18:38:47 2015 : Info: [peap] Done initial handshake
Tue Dec 29 18:38:47 2015 : Info: [peap] eaptls_process returned 7
Tue Dec 29 18:38:47 2015 : Info: [peap] EAPTLS_OK
Tue Dec 29 18:38:47 2015 : Info: [peap] Session established. Decoding tunneled attributes.
Tue Dec 29 18:38:47 2015 : Info: [peap] Peap state send tlv failure
Tue Dec 29 18:38:47 2015 : Info: [peap] Received EAP-TLV response.
Tue Dec 29 18:38:47 2015 : Info: [peap] The users session was previously rejected: returning reject (again.)
Tue Dec 29 18:38:47 2015 : Info: [peap] *** This means you need to read the PREVIOUS messages in the debug output
Tue Dec 29 18:38:47 2015 : Info: [peap] *** to find out the reason why the user was rejected.
Tue Dec 29 18:38:47 2015 : Info: [peap] *** Look for "reject" or "fail". Those earlier messages will tell you.
Tue Dec 29 18:38:47 2015 : Info: [peap] *** what went wrong, and how to fix the problem.
Tue Dec 29 18:38:47 2015 : Info: [eap] Handler failed in EAP/peap
Tue Dec 29 18:38:47 2015 : Info: [eap] Failed in EAP select
Tue Dec 29 18:38:47 2015 : Info: ++[eap] = invalid
Tue Dec 29 18:38:47 2015 : Info: +} # group authenticate = invalid
Tue Dec 29 18:38:47 2015 : Info: Failed to authenticate the user.
Tue Dec 29 18:38:47 2015 : Info: Using Post-Auth-Type REJECT
Tue Dec 29 18:38:47 2015 : Info: # Executing group from file /etc/freeradius/sites-enabled/default
Tue Dec 29 18:38:47 2015 : Info: +group REJECT {
Tue Dec 29 18:38:47 2015 : Info: [sql] expand: %{User-Name} -> ccc
Tue Dec 29 18:38:47 2015 : Info: [sql] sql_set_user escaped user --> 'ccc'
Tue Dec 29 18:38:47 2015 : Info: [sql] expand: %{User-Password} ->
Tue Dec 29 18:38:47 2015 : Info: [sql] ... expanding second conditional
Tue Dec 29 18:38:47 2015 : Info: [sql] expand: %{Chap-Password} ->
Tue Dec 29 18:38:47 2015 : Info: [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ccc', '', 'Access-Reject', '2015-12-29 18:38:47')
Tue Dec 29 18:38:47 2015 : Debug: rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ccc', '', 'Access-Reject', '2015-12-29 18:38:47')
Tue Dec 29 18:38:47 2015 : Debug: rlm_sql (sql): Reserving sql socket id: 29
Tue Dec 29 18:38:47 2015 : Debug: rlm_sql (sql): Released sql socket id: 29
Tue Dec 29 18:38:47 2015 : Info: ++[sql] = ok
Tue Dec 29 18:38:47 2015 : Info: [attr_filter.access_reject] expand: %{User-Name} -> ccc
Tue Dec 29 18:38:47 2015 : Debug: attr_filter: Matched entry DEFAULT at line 11
Tue Dec 29 18:38:47 2015 : Info: ++[attr_filter.access_reject] = updated
Tue Dec 29 18:38:47 2015 : Info: +} # group REJECT = updated
Tue Dec 29 18:38:47 2015 : Info: Delaying reject of request 8 for 1 seconds
Tue Dec 29 18:38:47 2015 : Debug: Going to the next request
Tue Dec 29 18:38:47 2015 : Debug: Waking up in 0.1 seconds.
Tue Dec 29 18:38:47 2015 : Info: Cleaning up request 0 ID 209 with timestamp +11
Tue Dec 29 18:38:47 2015 : Debug: Waking up in 0.3 seconds.
Tue Dec 29 18:38:47 2015 : Info: Cleaning up request 1 ID 210 with timestamp +11
Tue Dec 29 18:38:47 2015 : Debug: Waking up in 0.3 seconds.
Tue Dec 29 18:38:48 2015 : Info: Cleaning up request 2 ID 211 with timestamp +12
Tue Dec 29 18:38:48 2015 : Debug: Waking up in 0.1 seconds.
Tue Dec 29 18:38:48 2015 : Info: Sending delayed reject for request 8
Sending Access-Reject of id 217 to 192.168.1.1 port 32779
EAP-Message = 0x04090004
Message-Authenticator = 0x00000000000000000000000000000000
找到解决方案，
问题是我没有配置 /etc/raddb/sites-available/inner-tunnel 文件来使用 sql