Framed-Route not appearing on the client

3 Jun 2022

      Good afternoon,

After I resolved the issue with the IP address not being present on the
client with Framed-IP-Address, I needed for the client to get a gateway to
the corresponding subnet.
Without that gateway, the client doesn't know where to go when it arrives
on the public interface.
I've looked at https://freeradius.org/rfc/rfc2865.html#Framed-Route and
took the example below without adding metric options.

test1.vpn       Service-Type == Framed-User
                Framed-IP-Address += 10.10.10.6,
                Framed-Route += "172.16.10.0/24 172.16.10.254",
                Framed-IP-Netmask += 255.255.255.0,
                Fall-Through = Yes

I've also tried "172.16.10.0 172.16.10.254", "172.16.10.0/24 172.16.10.254
1 2 -1 3 400" but when doing ipconfig, there is no change nor route added
with route print.

Here are the radiusd -X log :

(1) Received Access-Request Id 110 from 127.0.0.1:39643 to 127.0.0.1:1812
length 169
(1)   User-Name = "test1.vpn"
(1)   NAS-Port-Type = Virtual
(1)   Service-Type = Framed-User
(1)   NAS-Port = 23
(1)   NAS-Port-Id = "test1.vpn"
(1)   NAS-IP-Address = X.X.X.220
(1)   Called-Station-Id = "X.X.X.220[4500]"
(1)   Calling-Station-Id = "X.X.X.211[4500]"
(1)   Acct-Session-Id = "1654243660-23"
(1)   EAP-Message = 0x0200000e0174657374312e76706e
(1)   NAS-Identifier = "strongSwan"
(1)   Message-Authenticator = 0xf9c61265bceb4790a3b47226f48e2c0e
(1) # Executing section authorize from file /etc/raddb/sites-enabled/default
(1)   authorize {
(1) files: users: Matched entry test1.vpn at line 3
(1)     [files] = ok
(1)     [preprocess] = ok
(1)     [mschap] = noop
(1) eap: Peer sent EAP Response (code 2) ID 0 length 14
(1) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the
rest of authorize
(1)     [eap] = ok
(1)   } # authorize = ok
(1) Found Auth-Type = eap
(1) # Executing group from file /etc/raddb/sites-enabled/default
(1)   authenticate {
(1) eap: Peer sent packet with method EAP Identity (1)
(1) eap: Calling submodule eap_md5 to process data
(1) eap_md5: Issuing MD5 Challenge
(1) eap: Sending EAP Request (code 1) ID 1 length 22
(1) eap: EAP session adding &reply:State = 0x1ee1c2c31ee0c6b6
(1)     [eap] = handled
(1)   } # authenticate = handled
(1) Using Post-Auth-Type Challenge
(1) Post-Auth-Type sub-section not found.  Ignoring.
(1) # Executing group from file /etc/raddb/sites-enabled/default
(1) Sent Access-Challenge Id 110 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(1)   Framed-IP-Address = 10.10.10.6
(1)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(1)   Framed-IP-Netmask = 255.255.255.0
(1)   EAP-Message = 0x01010016041090b5fda5bb3dcbe908a3f3380788de98
(1)   Message-Authenticator = 0x00000000000000000000000000000000
(1)   State = 0x1ee1c2c31ee0c6b67da4e0496fb672ca
(1) Finished request
Waking up in 4.9 seconds.
(2) Received Access-Request Id 111 from 127.0.0.1:39643 to 127.0.0.1:1812
length 179
(2)   User-Name = "test1.vpn"
(2)   NAS-Port-Type = Virtual
(2)   Service-Type = Framed-User
(2)   NAS-Port = 23
(2)   NAS-Port-Id = "test1.vpn"
(2)   NAS-IP-Address = X.X.X.220
(2)   Called-Station-Id = "X.X.X.220[4500]"
(2)   Calling-Station-Id = "X.X.X.211[4500]"
(2)   Acct-Session-Id = "1654243660-23"
(2)   EAP-Message = 0x020100060319
(2)   NAS-Identifier = "strongSwan"
(2)   State = 0x1ee1c2c31ee0c6b67da4e0496fb672ca
(2)   Message-Authenticator = 0x7fb7e39123c77d8bf07ba2d89019a7f6
(2) session-state: No cached attributes
(2) # Executing section authorize from file /etc/raddb/sites-enabled/default
(2)   authorize {
(2) files: users: Matched entry test1.vpn at line 3
(2)     [files] = ok
(2)     [preprocess] = ok
(2)     [mschap] = noop
(2) eap: Peer sent EAP Response (code 2) ID 1 length 6
(2) eap: No EAP Start, assuming it's an on-going EAP conversation
(2)     [eap] = updated
(2)     [expiration] = noop
(2)     [logintime] = noop
(2)   } # authorize = updated
(2) Found Auth-Type = eap
(2) # Executing group from file /etc/raddb/sites-enabled/default
(2)   authenticate {
(2) eap: Expiring EAP session with state 0x1ee1c2c31ee0c6b6
(2) eap: Finished EAP session with state 0x1ee1c2c31ee0c6b6
(2) eap: Previous EAP request found for state 0x1ee1c2c31ee0c6b6, released
from the list
(2) eap: Peer sent packet with method EAP NAK (3)
(2) eap: Found mutually acceptable type PEAP (25)
(2) eap: Calling submodule eap_peap to process data
(2) eap_peap: Initiating new TLS session
(2) eap_peap: [eaptls start] = request
(2) eap: Sending EAP Request (code 1) ID 2 length 6
(2) eap: EAP session adding &reply:State = 0x1ee1c2c31fe3dbb6
(2)     [eap] = handled
(2)   } # authenticate = handled
(2) Using Post-Auth-Type Challenge
(2) Post-Auth-Type sub-section not found.  Ignoring.
(2) # Executing group from file /etc/raddb/sites-enabled/default
(2) Sent Access-Challenge Id 111 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(2)   Framed-IP-Address = 10.10.10.6
(2)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(2)   Framed-IP-Netmask = 255.255.255.0
(2)   EAP-Message = 0x010200061920
(2)   Message-Authenticator = 0x00000000000000000000000000000000
(2)   State = 0x1ee1c2c31fe3dbb67da4e0496fb672ca
(2) Finished request
Waking up in 4.9 seconds.
(3) Received Access-Request Id 112 from 127.0.0.1:39643 to 127.0.0.1:1812
length 345
(3)   User-Name = "test1.vpn"
(3)   NAS-Port-Type = Virtual
(3)   Service-Type = Framed-User
(3)   NAS-Port = 23
(3)   NAS-Port-Id = "test1.vpn"
(3)   NAS-IP-Address = X.X.X.220
(3)   Called-Station-Id = "X.X.X.220[4500]"
(3)   Calling-Station-Id = "X.X.X.211[4500]"
(3)   Acct-Session-Id = "1654243660-23"
(3)   EAP-Message =
0x020200ac1980000000a2160303009d0100009903036299fd276a1f5725294c54bbe39e76a2b6b0fd113394be604d5a58554580473400002ac02cc02bc030c02f009f009ec024c023c028c027c00ac009c014c013009d009c003d003c0035002f000a01000046000500050100000000000a00080006001d00170018000b00020100000d001a00180804080508060401050102010403050302030202060106030023000000170000ff01000100
(3)   NAS-Identifier = "strongSwan"
(3)   State = 0x1ee1c2c31fe3dbb67da4e0496fb672ca
(3)   Message-Authenticator = 0xad9955152429f7011a592db314060109
(3) session-state: No cached attributes
(3) # Executing section authorize from file /etc/raddb/sites-enabled/default
(3)   authorize {
(3) files: users: Matched entry test1.vpn at line 3
(3)     [files] = ok
(3)     [preprocess] = ok
(3)     [mschap] = noop
(3) eap: Peer sent EAP Response (code 2) ID 2 length 172
(3) eap: Continuing tunnel setup
(3)     [eap] = ok
(3)   } # authorize = ok
(3) Found Auth-Type = eap
(3) # Executing group from file /etc/raddb/sites-enabled/default
(3)   authenticate {
(3) eap: Expiring EAP session with state 0x1ee1c2c31fe3dbb6
(3) eap: Finished EAP session with state 0x1ee1c2c31fe3dbb6
(3) eap: Previous EAP request found for state 0x1ee1c2c31fe3dbb6, released
from the list
(3) eap: Peer sent packet with method EAP PEAP (25)
(3) eap: Calling submodule eap_peap to process data
(3) eap_peap: Continuing EAP-TLS
(3) eap_peap: Peer indicated complete TLS record size will be 162 bytes
(3) eap_peap: Got complete TLS record (162 bytes)
(3) eap_peap: [eaptls verify] = length included
(3) eap_peap: (other): before SSL initialization
(3) eap_peap: TLS_accept: before SSL initialization
(3) eap_peap: TLS_accept: before SSL initialization
(3) eap_peap: <<< recv TLS 1.3  [length 009d]
(3) eap_peap: TLS_accept: SSLv3/TLS read client hello
(3) eap_peap: >>> send TLS 1.2  [length 003d]
(3) eap_peap: TLS_accept: SSLv3/TLS write server hello
(3) eap_peap: >>> send TLS 1.2  [length 0a0e]
(3) eap_peap: TLS_accept: SSLv3/TLS write certificate
(3) eap_peap: >>> send TLS 1.2  [length 024d]
(3) eap_peap: TLS_accept: SSLv3/TLS write key exchange
(3) eap_peap: >>> send TLS 1.2  [length 0004]
(3) eap_peap: TLS_accept: SSLv3/TLS write server done
(3) eap_peap: TLS_accept: Need to read more data: SSLv3/TLS write server
done
(3) eap_peap: TLS - In Handshake Phase
(3) eap_peap: TLS - got 3248 bytes of data
(3) eap_peap: [eaptls process] = handled
(3) eap: Sending EAP Request (code 1) ID 3 length 1004
(3) eap: EAP session adding &reply:State = 0x1ee1c2c31ce2dbb6
(3)     [eap] = handled
(3)   } # authenticate = handled
(3) Using Post-Auth-Type Challenge
(3) Post-Auth-Type sub-section not found.  Ignoring.
(3) # Executing group from file /etc/raddb/sites-enabled/default
(3) Sent Access-Challenge Id 112 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(3)   Framed-IP-Address = 10.10.10.6
(3)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(3)   Framed-IP-Netmask = 255.255.255.0
(3)   EAP-Message =
0x010303ec19c000000cb0160303003d0200003903037e92fcf5e372d80e8182311960e59e09ca9458b54f8cfddf2cef5072b1abcc1e00c030000011ff01000100000b000403000102001700001603030a0e0b000a0a000a0700050930820505308202eda003020102020859501ffb058af674300d06092a864886f70d01010c05003018311630140603550403130d4c696e6b736f2056504e204341301e170d3232303532373134333135355a170d3332303532343134333135355a3018311630140603550403130d3137382e31382e36322e32323030820222300d06092a864886f70d01010105000382020f003082020a0282020100a78d1c2b41f372a12f579b055680a56749aa46f0ec6c0031b424589ca4371f4904485b011adfebb5de0b47cd85a6009f7ed0d2f8b2ed60d624322e67c6ac0d92f8044774570dddfb12512d3f354dce91b84bab8c1281abc72f7776fb0aaf3d30ad0daf0c69a07709007fb40f2aff69de1effcbe748cab7c6a889d7df5e92488e33
(3)   Message-Authenticator = 0x00000000000000000000000000000000
(3)   State = 0x1ee1c2c31ce2dbb67da4e0496fb672ca
(3) Finished request
Waking up in 4.9 seconds.
(4) Received Access-Request Id 113 from 127.0.0.1:39643 to 127.0.0.1:1812
length 179
(4)   User-Name = "test1.vpn"
(4)   NAS-Port-Type = Virtual
(4)   Service-Type = Framed-User
(4)   NAS-Port = 23
(4)   NAS-Port-Id = "test1.vpn"
(4)   NAS-IP-Address = X.X.X.220
(4)   Called-Station-Id = "X.X.X.220[4500]"
(4)   Calling-Station-Id = "X.X.X.11[4500]"
(4)   Acct-Session-Id = "1654243660-23"
(4)   EAP-Message = 0x020300061900
(4)   NAS-Identifier = "strongSwan"
(4)   State = 0x1ee1c2c31ce2dbb67da4e0496fb672ca
(4)   Message-Authenticator = 0xe9255862a72fdefe69d2869cdb9daa64
(4) session-state: No cached attributes
(4) # Executing section authorize from file /etc/raddb/sites-enabled/default
(4)   authorize {
(4) files: users: Matched entry test1.vpn at line 3
(4)     [files] = ok
(4)     [preprocess] = ok
(4)     [mschap] = noop
(4) eap: Peer sent EAP Response (code 2) ID 3 length 6
(4) eap: Continuing tunnel setup
(4)     [eap] = ok
(4)   } # authorize = ok
(4) Found Auth-Type = eap
(4) # Executing group from file /etc/raddb/sites-enabled/default
(4)   authenticate {
(4) eap: Expiring EAP session with state 0x1ee1c2c31ce2dbb6
(4) eap: Finished EAP session with state 0x1ee1c2c31ce2dbb6
(4) eap: Previous EAP request found for state 0x1ee1c2c31ce2dbb6, released
from the list
(4) eap: Peer sent packet with method EAP PEAP (25)
(4) eap: Calling submodule eap_peap to process data
(4) eap_peap: Continuing EAP-TLS
(4) eap_peap: Peer ACKed our handshake fragment
(4) eap_peap: [eaptls verify] = request
(4) eap_peap: [eaptls process] = handled
(4) eap: Sending EAP Request (code 1) ID 4 length 1000
(4) eap: EAP session adding &reply:State = 0x1ee1c2c31de5dbb6
(4)     [eap] = handled
(4)   } # authenticate = handled
(4) Using Post-Auth-Type Challenge
(4) Post-Auth-Type sub-section not found.  Ignoring.
(4) # Executing group from file /etc/raddb/sites-enabled/default
(4) Sent Access-Challenge Id 113 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(4)   Framed-IP-Address = 10.10.10.6
(4)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(4)   Framed-IP-Netmask = 255.255.255.0
(4)   EAP-Message =
0x010403e81940bebf80d34d5d2ffadfe99593245c430b0545f71e325611a471ac019a0eb1b4cc51be9e4c4c6d7173cf00d6b53abe40a709dc7013a54897189721d836b31ae0ba84666749f762e02ab0f7b47d56d4ed0985084c55389e67476016143a29513ce10e4f779ba0e79cfedc620ce3b17c114081e2081221b32789bb7a167feb276b90bd6e5ccf3963a97c3da2a7cc5bee2b19fa21a4aa2f4a0abb2699dbe10fdbd42e93a395609bab8aded14fe6829a91017a7553d91e662a960b104d715a882298b2b57a106b608d5cbf18a416f047f92f8d6edc4631a136a88a1316574dfd306656f721427222732b84808fb63b38afe9f956af9969f506dbed0be473b1004960514231c75a8daff60a37ffe26fc85dcfb077c45ef88166b71a0ede035f7c5d79a749f30c64f5ed4e03ed8436e8f08c1d460fc0bd260ec944f99d183119868e804a7f93de415baea77ff7a29672b674e735b9d9170afd483208bec971d40ec0cb8b901f37c69d44d5c4d88bb63f59744c508a
(4)   Message-Authenticator = 0x00000000000000000000000000000000
(4)   State = 0x1ee1c2c31de5dbb67da4e0496fb672ca
(4) Finished request
Waking up in 4.9 seconds.
(5) Received Access-Request Id 114 from 127.0.0.1:39643 to 127.0.0.1:1812
length 179
(5)   User-Name = "test1.vpn"
(5)   NAS-Port-Type = Virtual
(5)   Service-Type = Framed-User
(5)   NAS-Port = 23
(5)   NAS-Port-Id = "test1.vpn"
(5)   NAS-IP-Address = X.X.X.220
(5)   Called-Station-Id = "X.X.X.20[4500]"
(5)   Calling-Station-Id = "X.X.X.211[4500]"
(5)   Acct-Session-Id = "1654243660-23"
(5)   EAP-Message = 0x020400061900
(5)   NAS-Identifier = "strongSwan"
(5)   State = 0x1ee1c2c31de5dbb67da4e0496fb672ca
(5)   Message-Authenticator = 0xea650ae4362cd184b3f28cddf49ad01c
(5) session-state: No cached attributes
(5) # Executing section authorize from file /etc/raddb/sites-enabled/default
(5)   authorize {
(5) files: users: Matched entry test1.vpn at line 3
(5)     [files] = ok
(5)     [preprocess] = ok
(5)     [mschap] = noop
(5) eap: Peer sent EAP Response (code 2) ID 4 length 6
(5) eap: Continuing tunnel setup
(5)     [eap] = ok
(5)   } # authorize = ok
(5) Found Auth-Type = eap
(5) # Executing group from file /etc/raddb/sites-enabled/default
(5)   authenticate {
(5) eap: Expiring EAP session with state 0x1ee1c2c31de5dbb6
(5) eap: Finished EAP session with state 0x1ee1c2c31de5dbb6
(5) eap: Previous EAP request found for state 0x1ee1c2c31de5dbb6, released
from the list
(5) eap: Peer sent packet with method EAP PEAP (25)
(5) eap: Calling submodule eap_peap to process data
(5) eap_peap: Continuing EAP-TLS
(5) eap_peap: Peer ACKed our handshake fragment
(5) eap_peap: [eaptls verify] = request
(5) eap_peap: [eaptls process] = handled
(5) eap: Sending EAP Request (code 1) ID 5 length 1000
(5) eap: EAP session adding &reply:State = 0x1ee1c2c31ae4dbb6
(5)     [eap] = handled
(5)   } # authenticate = handled
(5) Using Post-Auth-Type Challenge
(5) Post-Auth-Type sub-section not found.  Ignoring.
(5) # Executing group from file /etc/raddb/sites-enabled/default
(5) Sent Access-Challenge Id 114 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(5)   Framed-IP-Address = 10.10.10.6
(5)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(5)   Framed-IP-Netmask = 255.255.255.0
(5)   EAP-Message =
0x010503e819407082cf40cfcee0f3f12cba3aef5822670128cd6f911798eef08198423886ccf7755c826cdcbe3a99ce66a9eae20d46d7161e7b750203010001a3423040300f0603551d130101ff040530030101ff300e0603551d0f0101ff040403020106301d0603551d0e04160414add6132f6bb457e0c198d140aba7a264e4dc0d8d300d06092a864886f70d01010c05000382020100902e25abac2dddd6ca56f04588ea1f33d011b08f31e625c387b2230a2f9f378387f2929f02a0e839e8ba589f3fa07aa97df211ce02ce75ca2eeff80a09234bc54ce1cb8be75c16b2356d36c1d4ad6bde1b5c8921a1e03d412bfd280c3cabe5b734bd209d9f8182cf64fd4ecf87ab4e677b6c9c70d10f25f6f2772a611a31fcb3e74a800142a211c766841ad6540913ba8c7b39025308a651829d2dfac79d8dac002e21bf72bd73ccf17774b31e0cd3fde6c927cfea62ed17982d4203aa7ab706fc7883dde5321895ae65e63ff503804f12ff80a8075e0f1f9b169d8a1adae22d
(5)   Message-Authenticator = 0x00000000000000000000000000000000
(5)   State = 0x1ee1c2c31ae4dbb67da4e0496fb672ca
(5) Finished request
Waking up in 4.9 seconds.
(6) Received Access-Request Id 115 from 127.0.0.1:39643 to 127.0.0.1:1812
length 179
(6)   User-Name = "test1.vpn"
(6)   NAS-Port-Type = Virtual
(6)   Service-Type = Framed-User
(6)   NAS-Port = 23
(6)   NAS-Port-Id = "test1.vpn"
(6)   NAS-IP-Address = X.X.X.220
(6)   Called-Station-Id = "X.X.X.220[4500]"
(6)   Calling-Station-Id = "X.X.X.211[4500]"
(6)   Acct-Session-Id = "1654243660-23"
(6)   EAP-Message = 0x020500061900
(6)   NAS-Identifier = "strongSwan"
(6)   State = 0x1ee1c2c31ae4dbb67da4e0496fb672ca
(6)   Message-Authenticator = 0x20f1a93bf98ff703c88607c5af6b39a3
(6) session-state: No cached attributes
(6) # Executing section authorize from file /etc/raddb/sites-enabled/default
(6)   authorize {
(6) files: users: Matched entry test1.vpn at line 3
(6)     [files] = ok
(6)     [preprocess] = ok
(6)     [mschap] = noop
(6) eap: Peer sent EAP Response (code 2) ID 5 length 6
(6) eap: Continuing tunnel setup
(6)     [eap] = ok
(6)   } # authorize = ok
(6) Found Auth-Type = eap
(6) # Executing group from file /etc/raddb/sites-enabled/default
(6)   authenticate {
(6) eap: Expiring EAP session with state 0x1ee1c2c31ae4dbb6
(6) eap: Finished EAP session with state 0x1ee1c2c31ae4dbb6
(6) eap: Previous EAP request found for state 0x1ee1c2c31ae4dbb6, released
from the list
(6) eap: Peer sent packet with method EAP PEAP (25)
(6) eap: Calling submodule eap_peap to process data
(6) eap_peap: Continuing EAP-TLS
(6) eap_peap: Peer ACKed our handshake fragment
(6) eap_peap: [eaptls verify] = request
(6) eap_peap: [eaptls process] = handled
(6) eap: Sending EAP Request (code 1) ID 6 length 272
(6) eap: EAP session adding &reply:State = 0x1ee1c2c31be7dbb6
(6)     [eap] = handled
(6)   } # authenticate = handled
(6) Using Post-Auth-Type Challenge
(6) Post-Auth-Type sub-section not found.  Ignoring.
(6) # Executing group from file /etc/raddb/sites-enabled/default
(6) Sent Access-Challenge Id 115 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(6)   Framed-IP-Address = 10.10.10.6
(6)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(6)   Framed-IP-Netmask = 255.255.255.0
(6)   EAP-Message =
0x01060110190045bbfea2a25b7e8d465f85db19d2c6adfcb56236fac607577500c9b037a86352ccf4dc51670cd331c20645898a411eb323c8bc56990eaff47e887dbfcaebdf5fdc625ef603c8071df374c07b34eaea9ca7556fac9c0fef6682cb69e5d7b6f4339ca198964a982d1f0071688c2f4478c76680dc14d8b72345e7e8bfcd3489a6174dbc15fb90ca991335861b23d2954940d70e68a2225e0145878ac9e3572c8608ac1c761a4748e153c6fa88d7ee6a116013bbf2c53b46015cbd3791b5810a12a4e84d5c599b35cfe1f0117c1ddf5ad5cb7bee5fde466be44ef29bf99204ee193662f60e6f9732be198cbb1d05b7649587c1c721bbef2cd8bc55f07ef4d7746ae38316030300040e000000
(6)   Message-Authenticator = 0x00000000000000000000000000000000
(6)   State = 0x1ee1c2c31be7dbb67da4e0496fb672ca
(6) Finished request
Waking up in 4.9 seconds.
(7) Received Access-Request Id 116 from 127.0.0.1:39643 to 127.0.0.1:1812
length 309
(7)   User-Name = "test1.vpn"
(7)   NAS-Port-Type = Virtual
(7)   Service-Type = Framed-User
(7)   NAS-Port = 23
(7)   NAS-Port-Id = "test1.vpn"
(7)   NAS-IP-Address = X.X.X.220
(7)   Called-Station-Id = "X.X.X.220[4500]"
(7)   Calling-Station-Id = "X.X.X.211[4500]"
(7)   Acct-Session-Id = "1654243660-23"
(7)   EAP-Message =
0x0206008819800000007e1603030046100000424104350848568eed83f107ec16f596aaac42de6ef55ab0b47108ddc32b1d0118178e819ea7f7fe7c22300f7a04817c3e3064a1d4124cf58a5d16433363f8b6c35c3b14030300010116030300280000000000000000d888cc0cad9ea9fd18e1a0e0812250561ed19861ad2fadbf6cfbc0e25c621fc2
(7)   NAS-Identifier = "strongSwan"
(7)   State = 0x1ee1c2c31be7dbb67da4e0496fb672ca
(7)   Message-Authenticator = 0x182aa5d5b9286e3520dacd1462d67272
(7) session-state: No cached attributes
(7) # Executing section authorize from file /etc/raddb/sites-enabled/default
(7)   authorize {
(7) files: users: Matched entry test1.vpn at line 3
(7)     [files] = ok
(7)     [preprocess] = ok
(7)     [mschap] = noop
(7) eap: Peer sent EAP Response (code 2) ID 6 length 136
(7) eap: Continuing tunnel setup
(7)     [eap] = ok
(7)   } # authorize = ok
(7) Found Auth-Type = eap
(7) # Executing group from file /etc/raddb/sites-enabled/default
(7)   authenticate {
(7) eap: Expiring EAP session with state 0x1ee1c2c31be7dbb6
(7) eap: Finished EAP session with state 0x1ee1c2c31be7dbb6
(7) eap: Previous EAP request found for state 0x1ee1c2c31be7dbb6, released
from the list
(7) eap: Peer sent packet with method EAP PEAP (25)
(7) eap: Calling submodule eap_peap to process data
(7) eap_peap: Continuing EAP-TLS
(7) eap_peap: Peer indicated complete TLS record size will be 126 bytes
(7) eap_peap: Got complete TLS record (126 bytes)
(7) eap_peap: [eaptls verify] = length included
(7) eap_peap: TLS_accept: SSLv3/TLS write server done
(7) eap_peap: <<< recv TLS 1.2  [length 0046]
(7) eap_peap: TLS_accept: SSLv3/TLS read client key exchange
(7) eap_peap: TLS_accept: SSLv3/TLS read change cipher spec
(7) eap_peap: <<< recv TLS 1.2  [length 0010]
(7) eap_peap: TLS_accept: SSLv3/TLS read finished
(7) eap_peap: >>> send TLS 1.2  [length 0001]
(7) eap_peap: TLS_accept: SSLv3/TLS write change cipher spec
(7) eap_peap: >>> send TLS 1.2  [length 0010]
(7) eap_peap: TLS_accept: SSLv3/TLS write finished
(7) eap_peap: (other): SSL negotiation finished successfully
(7) eap_peap: TLS - Connection Established
(7) eap_peap: TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(7) eap_peap: TLS-Session-Version = "TLS 1.2"
(7) eap_peap: TLS - got 51 bytes of data
(7) eap_peap: [eaptls process] = handled
(7) eap: Sending EAP Request (code 1) ID 7 length 57
(7) eap: EAP session adding &reply:State = 0x1ee1c2c318e6dbb6
(7)     [eap] = handled
(7)   } # authenticate = handled
(7) Using Post-Auth-Type Challenge
(7) Post-Auth-Type sub-section not found.  Ignoring.
(7) # Executing group from file /etc/raddb/sites-enabled/default
(7) session-state: Saving cached attributes
(7)   TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(7)   TLS-Session-Version = "TLS 1.2"
(7) Sent Access-Challenge Id 116 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(7)   Framed-IP-Address = 10.10.10.6
(7)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(7)   Framed-IP-Netmask = 255.255.255.0
(7)   EAP-Message =
0x01070039190014030300010116030300289e5cd13943bc517eff9a9cf4bcdb9fa2988a382c89f04e68524617ba480dfc733454c4394c3cda2d
(7)   Message-Authenticator = 0x00000000000000000000000000000000
(7)   State = 0x1ee1c2c318e6dbb67da4e0496fb672ca
(7) Finished request
Waking up in 4.9 seconds.
(8) Received Access-Request Id 117 from 127.0.0.1:39643 to 127.0.0.1:1812
length 179
(8)   User-Name = "test1.vpn"
(8)   NAS-Port-Type = Virtual
(8)   Service-Type = Framed-User
(8)   NAS-Port = 23
(8)   NAS-Port-Id = "test1.vpn"
(8)   NAS-IP-Address = X.X.X.220
(8)   Called-Station-Id = "X.X.X.220[4500]"
(8)   Calling-Station-Id = "X.X.X.211[4500]"
(8)   Acct-Session-Id = "1654243660-23"
(8)   EAP-Message = 0x020700061900
(8)   NAS-Identifier = "strongSwan"
(8)   State = 0x1ee1c2c318e6dbb67da4e0496fb672ca
(8)   Message-Authenticator = 0x87ca357171c042c52eae09a2fdad8fd4
(8) Restoring &session-state
(8)   &session-state:TLS-Session-Cipher-Suite =
"ECDHE-RSA-AES256-GCM-SHA384"
(8)   &session-state:TLS-Session-Version = "TLS 1.2"
(8) # Executing section authorize from file /etc/raddb/sites-enabled/default
(8)   authorize {
(8) files: users: Matched entry test1.vpn at line 3
(8)     [files] = ok
(8)     [preprocess] = ok
(8)     [mschap] = noop
(8) eap: Peer sent EAP Response (code 2) ID 7 length 6
(8) eap: Continuing tunnel setup
(8)     [eap] = ok
(8)   } # authorize = ok
(8) Found Auth-Type = eap
(8) # Executing group from file /etc/raddb/sites-enabled/default
(8)   authenticate {
(8) eap: Expiring EAP session with state 0x1ee1c2c318e6dbb6
(8) eap: Finished EAP session with state 0x1ee1c2c318e6dbb6
(8) eap: Previous EAP request found for state 0x1ee1c2c318e6dbb6, released
from the list
(8) eap: Peer sent packet with method EAP PEAP (25)
(8) eap: Calling submodule eap_peap to process data
(8) eap_peap: Continuing EAP-TLS
(8) eap_peap: Peer ACKed our handshake fragment.  handshake is finished
(8) eap_peap: [eaptls verify] = success
(8) eap_peap: [eaptls process] = success
(8) eap_peap: Session established.  Decoding tunneled attributes
(8) eap_peap: PEAP state TUNNEL ESTABLISHED
(8) eap: Sending EAP Request (code 1) ID 8 length 40
(8) eap: EAP session adding &reply:State = 0x1ee1c2c319e9dbb6
(8)     [eap] = handled
(8)   } # authenticate = handled
(8) Using Post-Auth-Type Challenge
(8) Post-Auth-Type sub-section not found.  Ignoring.
(8) # Executing group from file /etc/raddb/sites-enabled/default
(8) session-state: Saving cached attributes
(8)   TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(8)   TLS-Session-Version = "TLS 1.2"
(8) Sent Access-Challenge Id 117 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(8)   Framed-IP-Address = 10.10.10.6
(8)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(8)   Framed-IP-Netmask = 255.255.255.0
(8)   EAP-Message =
0x010800281900170303001d9e5cd13943bc517f1ca9c374ef3b22325c3209c2e3d6adb4d0ef3ace0c
(8)   Message-Authenticator = 0x00000000000000000000000000000000
(8)   State = 0x1ee1c2c319e9dbb67da4e0496fb672ca
(8) Finished request
Waking up in 4.9 seconds.
(9) Received Access-Request Id 118 from 127.0.0.1:39643 to 127.0.0.1:1812
length 218
(9)   User-Name = "test1.vpn"
(9)   NAS-Port-Type = Virtual
(9)   Service-Type = Framed-User
(9)   NAS-Port = 23
(9)   NAS-Port-Id = "test1.vpn"
(9)   NAS-IP-Address = X.X.X.220
(9)   Called-Station-Id = "X.X.X.220[4500]"
(9)   Calling-Station-Id = "X.X.X.211[4500]"
(9)   Acct-Session-Id = "1654243660-23"
(9)   EAP-Message =
0x0208002d190017030300220000000000000001477baf4933f3c4877115c28e5e2c234662d5e7dc19c58d0ff202
(9)   NAS-Identifier = "strongSwan"
(9)   State = 0x1ee1c2c319e9dbb67da4e0496fb672ca
(9)   Message-Authenticator = 0x8fb59e4cd4bfb6499fd57e90219e1015
(9) Restoring &session-state
(9)   &session-state:TLS-Session-Cipher-Suite =
"ECDHE-RSA-AES256-GCM-SHA384"
(9)   &session-state:TLS-Session-Version = "TLS 1.2"
(9) # Executing section authorize from file /etc/raddb/sites-enabled/default
(9)   authorize {
(9) files: users: Matched entry test1.vpn at line 3
(9)     [files] = ok
(9)     [preprocess] = ok
(9)     [mschap] = noop
(9) eap: Peer sent EAP Response (code 2) ID 8 length 45
(9) eap: Continuing tunnel setup
(9)     [eap] = ok
(9)   } # authorize = ok
(9) Found Auth-Type = eap
(9) # Executing group from file /etc/raddb/sites-enabled/default
(9)   authenticate {
(9) eap: Expiring EAP session with state 0x1ee1c2c319e9dbb6
(9) eap: Finished EAP session with state 0x1ee1c2c319e9dbb6
(9) eap: Previous EAP request found for state 0x1ee1c2c319e9dbb6, released
from the list
(9) eap: Peer sent packet with method EAP PEAP (25)
(9) eap: Calling submodule eap_peap to process data
(9) eap_peap: Continuing EAP-TLS
(9) eap_peap: [eaptls verify] = ok
(9) eap_peap: Done initial handshake
(9) eap_peap: [eaptls process] = ok
(9) eap_peap: Session established.  Decoding tunneled attributes
(9) eap_peap: PEAP state WAITING FOR INNER IDENTITY
(9) eap_peap: Identity - test1.vpn
(9) eap_peap: Got inner identity 'test1.vpn'
(9) eap_peap: Setting default EAP type for tunneled EAP session
(9) eap_peap: Got tunneled request
(9) eap_peap:   EAP-Message = 0x0208000e0174657374312e76706e
(9) eap_peap: Setting User-Name to test1.vpn
(9) eap_peap: Sending tunneled request to inner-tunnel
(9) eap_peap:   EAP-Message = 0x0208000e0174657374312e76706e
(9) eap_peap:   FreeRADIUS-Proxied-To = 127.0.0.1
(9) eap_peap:   User-Name = "test1.vpn"
(9) Virtual server inner-tunnel received request
(9)   EAP-Message = 0x0208000e0174657374312e76706e
(9)   FreeRADIUS-Proxied-To = 127.0.0.1
(9)   User-Name = "test1.vpn"
(9) WARNING: Outer and inner identities are the same.  User privacy is
compromised.
(9) server inner-tunnel {
(9)   # Executing section authorize from file
/etc/raddb/sites-enabled/inner-tunnel
(9)     authorize {
(9)       policy filter_username {
(9)         if (&User-Name) {
(9)         if (&User-Name)  -> TRUE
(9)         if (&User-Name)  {
(9)           if (&User-Name =~ / /) {
(9)           if (&User-Name =~ / /)  -> FALSE
(9)           if (&User-Name =~ /@[^@]*@/ ) {
(9)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(9)           if (&User-Name =~ /\.\./ ) {
(9)           if (&User-Name =~ /\.\./ )  -> FALSE
(9)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(9)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))
-> FALSE
(9)           if (&User-Name =~ /\.$/)  {
(9)           if (&User-Name =~ /\.$/)   -> FALSE
(9)           if (&User-Name =~ /@\./)  {
(9)           if (&User-Name =~ /@\./)   -> FALSE
(9)         } # if (&User-Name)  = notfound
(9)       } # policy filter_username = notfound
(9)       [mschap] = noop
(9) eap: Peer sent EAP Response (code 2) ID 8 length 14
(9) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the
rest of authorize
(9)       [eap] = ok
(9)     } # authorize = ok
(9)   Found Auth-Type = eap
(9)   # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(9)     authenticate {
(9) eap: Peer sent packet with method EAP Identity (1)
(9) eap: Calling submodule eap_mschapv2 to process data
(9) eap_mschapv2: Issuing Challenge
(9) eap: Sending EAP Request (code 1) ID 9 length 43
(9) eap: EAP session adding &reply:State = 0x77d61e8777df0400
(9)       [eap] = handled
(9)     } # authenticate = handled
(9) } # server inner-tunnel
(9) Virtual server sending reply
(9)   EAP-Message =
0x0109002b1a0109002610f3f955ef73c249d34cc08653d38cf2e1667265657261646975732d332e302e3230
(9)   Message-Authenticator = 0x00000000000000000000000000000000
(9)   State = 0x77d61e8777df0400aa8dafc0f122a1ae
(9) eap_peap: Got tunneled reply code 11
(9) eap_peap:   EAP-Message =
0x0109002b1a0109002610f3f955ef73c249d34cc08653d38cf2e1667265657261646975732d332e302e3230
(9) eap_peap:   Message-Authenticator = 0x00000000000000000000000000000000
(9) eap_peap:   State = 0x77d61e8777df0400aa8dafc0f122a1ae
(9) eap_peap: Got tunneled reply RADIUS code 11
(9) eap_peap:   EAP-Message =
0x0109002b1a0109002610f3f955ef73c249d34cc08653d38cf2e1667265657261646975732d332e302e3230
(9) eap_peap:   Message-Authenticator = 0x00000000000000000000000000000000
(9) eap_peap:   State = 0x77d61e8777df0400aa8dafc0f122a1ae
(9) eap_peap: Got tunneled Access-Challenge
(9) eap: Sending EAP Request (code 1) ID 9 length 74
(9) eap: EAP session adding &reply:State = 0x1ee1c2c316e8dbb6
(9)     [eap] = handled
(9)   } # authenticate = handled
(9) Using Post-Auth-Type Challenge
(9) Post-Auth-Type sub-section not found.  Ignoring.
(9) # Executing group from file /etc/raddb/sites-enabled/default
(9) session-state: Saving cached attributes
(9)   TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(9)   TLS-Session-Version = "TLS 1.2"
(9) Sent Access-Challenge Id 118 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(9)   Framed-IP-Address = 10.10.10.6
(9)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(9)   Framed-IP-Netmask = 255.255.255.0
(9)   EAP-Message =
0x0109004a1900170303003f9e5cd13943bc51807d6489913fdb112a1ac5f51887be8e53c2db8b26c3e19c0680cc9e3070e835df3c6fed3a82ea228f01962130d389d61ed1461f8d86452c
(9)   Message-Authenticator = 0x00000000000000000000000000000000
(9)   State = 0x1ee1c2c316e8dbb67da4e0496fb672ca
(9) Finished request
Waking up in 4.9 seconds.
(10) Received Access-Request Id 119 from 127.0.0.1:39643 to 127.0.0.1:1812
length 272
(10)   User-Name = "test1.vpn"
(10)   NAS-Port-Type = Virtual
(10)   Service-Type = Framed-User
(10)   NAS-Port = 23
(10)   NAS-Port-Id = "test1.vpn"
(10)   NAS-IP-Address = X.X.X.220
(10)   Called-Station-Id = "X.X.X.220[4500]"
(10)   Calling-Station-Id = "X.X.X.211[4500]"
(10)   Acct-Session-Id = "1654243660-23"
(10)   EAP-Message =
0x02090063190017030300580000000000000002a2cc1798c3785a7dd9aec21bf28e16fc97365825b7ac6559c3134aff1f443e5e1680ad67a304ace789531e464b1afdcd3b20c0d5dafd9a0b1a9cfcc164adf2d449a8662c460150ee7a9b98a035ee7285
(10)   NAS-Identifier = "strongSwan"
(10)   State = 0x1ee1c2c316e8dbb67da4e0496fb672ca
(10)   Message-Authenticator = 0x825d8ace59e7de2fe46bf97ee5bf0b3e
(10) Restoring &session-state
(10)   &session-state:TLS-Session-Cipher-Suite =
"ECDHE-RSA-AES256-GCM-SHA384"
(10)   &session-state:TLS-Session-Version = "TLS 1.2"
(10) # Executing section authorize from file
/etc/raddb/sites-enabled/default
(10)   authorize {
(10) files: users: Matched entry test1.vpn at line 3
(10)     [files] = ok
(10)     [preprocess] = ok
(10)     [mschap] = noop
(10) eap: Peer sent EAP Response (code 2) ID 9 length 99
(10) eap: Continuing tunnel setup
(10)     [eap] = ok
(10)   } # authorize = ok
(10) Found Auth-Type = eap
(10) # Executing group from file /etc/raddb/sites-enabled/default
(10)   authenticate {
(10) eap: Expiring EAP session with state 0x77d61e8777df0400
(10) eap: Finished EAP session with state 0x1ee1c2c316e8dbb6
(10) eap: Previous EAP request found for state 0x1ee1c2c316e8dbb6, released
from the list
(10) eap: Peer sent packet with method EAP PEAP (25)
(10) eap: Calling submodule eap_peap to process data
(10) eap_peap: Continuing EAP-TLS
(10) eap_peap: [eaptls verify] = ok
(10) eap_peap: Done initial handshake
(10) eap_peap: [eaptls process] = ok
(10) eap_peap: Session established.  Decoding tunneled attributes
(10) eap_peap: PEAP state phase2
(10) eap_peap: EAP method MSCHAPv2 (26)
(10) eap_peap: Got tunneled request
(10) eap_peap:   EAP-Message =
0x020900441a0209003f3142e5d9b195ccee99d43e70b16db5d6f50000000000000000ec7383cd297a92e7054e42ca28029f0abf7a912249fb42e40074657374312e76706e
(10) eap_peap: Setting User-Name to test1.vpn
(10) eap_peap: Sending tunneled request to inner-tunnel
(10) eap_peap:   EAP-Message =
0x020900441a0209003f3142e5d9b195ccee99d43e70b16db5d6f50000000000000000ec7383cd297a92e7054e42ca28029f0abf7a912249fb42e40074657374312e76706e
(10) eap_peap:   FreeRADIUS-Proxied-To = 127.0.0.1
(10) eap_peap:   User-Name = "test1.vpn"
(10) eap_peap:   State = 0x77d61e8777df0400aa8dafc0f122a1ae
(10) Virtual server inner-tunnel received request
(10)   EAP-Message =
0x020900441a0209003f3142e5d9b195ccee99d43e70b16db5d6f50000000000000000ec7383cd297a92e7054e42ca28029f0abf7a912249fb42e40074657374312e76706e
(10)   FreeRADIUS-Proxied-To = 127.0.0.1
(10)   User-Name = "test1.vpn"
(10)   State = 0x77d61e8777df0400aa8dafc0f122a1ae
(10) WARNING: Outer and inner identities are the same.  User privacy is
compromised.
(10) server inner-tunnel {
(10)   session-state: No cached attributes
(10)   # Executing section authorize from file
/etc/raddb/sites-enabled/inner-tunnel
(10)     authorize {
(10)       policy filter_username {
(10)         if (&User-Name) {
(10)         if (&User-Name)  -> TRUE
(10)         if (&User-Name)  {
(10)           if (&User-Name =~ / /) {
(10)           if (&User-Name =~ / /)  -> FALSE
(10)           if (&User-Name =~ /@[^@]*@/ ) {
(10)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(10)           if (&User-Name =~ /\.\./ ) {
(10)           if (&User-Name =~ /\.\./ )  -> FALSE
(10)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(10)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))
-> FALSE
(10)           if (&User-Name =~ /\.$/)  {
(10)           if (&User-Name =~ /\.$/)   -> FALSE
(10)           if (&User-Name =~ /@\./)  {
(10)           if (&User-Name =~ /@\./)   -> FALSE
(10)         } # if (&User-Name)  = notfound
(10)       } # policy filter_username = notfound
(10)       [mschap] = noop
(10) eap: Peer sent EAP Response (code 2) ID 9 length 68
(10) eap: No EAP Start, assuming it's an on-going EAP conversation
(10)       [eap] = updated
(10)       [files] = noop
(10)       [expiration] = noop
(10)       [logintime] = noop
Not doing PAP as Auth-Type is already set.
(10)       [pap] = noop
(10)     } # authorize = updated
(10)   Found Auth-Type = eap
(10)   # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(10)     authenticate {
(10) eap: Expiring EAP session with state 0x77d61e8777df0400
(10) eap: Finished EAP session with state 0x77d61e8777df0400
(10) eap: Previous EAP request found for state 0x77d61e8777df0400, released
from the list
(10) eap: Peer sent packet with method EAP MSCHAPv2 (26)
(10) eap: Calling submodule eap_mschapv2 to process data
(10) eap_mschapv2: # Executing group from file
/etc/raddb/sites-enabled/inner-tunnel
(10) eap_mschapv2:   authenticate {
(10) mschap: Creating challenge hash with username: test1.vpn
(10) mschap: Client is using MS-CHAPv2
(10) mschap: Executing: /usr/bin/ntlm_auth --request-nt-key
--allow-mschapv2 --username=%{mschap:User-Name} --domain=BRANCHET
--challenge=%{mschap:Challenge:-01} --nt-response=%{mschap:NT-Response:-00}:
(10) mschap: EXPAND --username=%{mschap:User-Name}
(10) mschap:    --> --username=test1.vpn
(10) mschap: Creating challenge hash with username: test1.vpn
(10) mschap: EXPAND --challenge=%{mschap:Challenge:-01}
(10) mschap:    --> --challenge=6bdb0d44a5236820
(10) mschap: EXPAND --nt-response=%{mschap:NT-Response:-00}
(10) mschap:    -->
--nt-response=ec7383cd297a92e7054e42ca28029f0abf7a912249fb42e4
lpcfg_do_global_parameter: WARNING: The "domain logons" option is deprecated
added interface ens3 ip=172.16.10.111 bcast=172.16.10.255
netmask=255.255.255.0
added interface ens4 ip=X.X.X.220 bcast=X.X.X.223 netmask=255.255.255.224
lp_load_ex: refreshing parameters
Initialising global parameters
rlimit_max: increasing rlimit_max (1024) to minimum Windows limit (16384)
Processing section "[global]"
lpcfg_do_global_parameter: WARNING: The "domain logons" option is deprecated
added interface ens3 ip=172.16.10.111 bcast=172.16.10.255
netmask=255.255.255.0
added interface ens4 ip=X.X.X.220 bcast=X.X.X.223 netmask=255.255.255.224
lp_load_ex: refreshing parameters
Initialising global parameters
rlimit_max: increasing rlimit_max (1024) to minimum Windows limit (16384)
Processing section "[global]"
lpcfg_do_global_parameter: WARNING: The "domain logons" option is deprecated
added interface ens3 ip=172.16.10.111 bcast=172.16.10.255
netmask=255.255.255.0
added interface ens4 ip=X.X.X.220 bcast=X.X.X.223 netmask=255.255.255.224
(10) mschap: Program returned code (0) and output 'NT_KEY:
6F5564CE191F31EAC91AE7DAFA4E36FE'
(10) mschap: Adding MS-CHAPv2 MPPE keys
(10) eap_mschapv2:     [mschap] = ok
(10) eap_mschapv2:   } # authenticate = ok
(10) eap_mschapv2: MSCHAP Success
(10) eap: Sending EAP Request (code 1) ID 10 length 51
(10) eap: EAP session adding &reply:State = 0x77d61e8776dc0400
(10)       [eap] = handled
(10)     } # authenticate = handled
(10) } # server inner-tunnel
(10) Virtual server sending reply
(10)   EAP-Message =
0x010a00331a0309002e533d41324131423732333038393939463532333138453331383439443931413235433841353138444246
(10)   Message-Authenticator = 0x00000000000000000000000000000000
(10)   State = 0x77d61e8776dc0400aa8dafc0f122a1ae
(10) eap_peap: Got tunneled reply code 11
(10) eap_peap:   EAP-Message =
0x010a00331a0309002e533d41324131423732333038393939463532333138453331383439443931413235433841353138444246
(10) eap_peap:   Message-Authenticator = 0x00000000000000000000000000000000
(10) eap_peap:   State = 0x77d61e8776dc0400aa8dafc0f122a1ae
(10) eap_peap: Got tunneled reply RADIUS code 11
(10) eap_peap:   EAP-Message =
0x010a00331a0309002e533d41324131423732333038393939463532333138453331383439443931413235433841353138444246
(10) eap_peap:   Message-Authenticator = 0x00000000000000000000000000000000
(10) eap_peap:   State = 0x77d61e8776dc0400aa8dafc0f122a1ae
(10) eap_peap: Got tunneled Access-Challenge
(10) eap: Sending EAP Request (code 1) ID 10 length 82
(10) eap: EAP session adding &reply:State = 0x1ee1c2c317ebdbb6
(10)     [eap] = handled
(10)   } # authenticate = handled
(10) Using Post-Auth-Type Challenge
(10) Post-Auth-Type sub-section not found.  Ignoring.
(10) # Executing group from file /etc/raddb/sites-enabled/default
(10) session-state: Saving cached attributes
(10)   TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(10)   TLS-Session-Version = "TLS 1.2"
(10) Sent Access-Challenge Id 119 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(10)   Framed-IP-Address = 10.10.10.6
(10)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(10)   Framed-IP-Netmask = 255.255.255.0
(10)   EAP-Message =
0x010a0052190017030300479e5cd13943bc518136eddfd30e4a130aa1b816b1a5bac0aed321dc3a80883d878486214198fedbabf9630e53826282e5335243a14ea3b0d33e6ee214eaee656c5d9324da46c6d2
(10)   Message-Authenticator = 0x00000000000000000000000000000000
(10)   State = 0x1ee1c2c317ebdbb67da4e0496fb672ca
(10) Finished request
Waking up in 4.7 seconds.
(11) Received Access-Request Id 120 from 127.0.0.1:39643 to 127.0.0.1:1812
length 210
(11)   User-Name = "test1.vpn"
(11)   NAS-Port-Type = Virtual
(11)   Service-Type = Framed-User
(11)   NAS-Port = 23
(11)   NAS-Port-Id = "test1.vpn"
(11)   NAS-IP-Address = X.X.X.220
(11)   Called-Station-Id = "X.X.X.220[4500]"
(11)   Calling-Station-Id = "X.X.X.211[4500]"
(11)   Acct-Session-Id = "1654243660-23"
(11)   EAP-Message =
0x020a00251900170303001a0000000000000003b2b96f8f71d71744735da3f7898a5dba681b
(11)   NAS-Identifier = "strongSwan"
(11)   State = 0x1ee1c2c317ebdbb67da4e0496fb672ca
(11)   Message-Authenticator = 0x288e9dc84922a54c0cc6ea5663be4b40
(11) Restoring &session-state
(11)   &session-state:TLS-Session-Cipher-Suite =
"ECDHE-RSA-AES256-GCM-SHA384"
(11)   &session-state:TLS-Session-Version = "TLS 1.2"
(11) # Executing section authorize from file
/etc/raddb/sites-enabled/default
(11)   authorize {
(11) files: users: Matched entry test1.vpn at line 3
(11)     [files] = ok
(11)     [preprocess] = ok
(11)     [mschap] = noop
(11) eap: Peer sent EAP Response (code 2) ID 10 length 37
(11) eap: Continuing tunnel setup
(11)     [eap] = ok
(11)   } # authorize = ok
(11) Found Auth-Type = eap
(11) # Executing group from file /etc/raddb/sites-enabled/default
(11)   authenticate {
(11) eap: Expiring EAP session with state 0x77d61e8776dc0400
(11) eap: Finished EAP session with state 0x1ee1c2c317ebdbb6
(11) eap: Previous EAP request found for state 0x1ee1c2c317ebdbb6, released
from the list
(11) eap: Peer sent packet with method EAP PEAP (25)
(11) eap: Calling submodule eap_peap to process data
(11) eap_peap: Continuing EAP-TLS
(11) eap_peap: [eaptls verify] = ok
(11) eap_peap: Done initial handshake
(11) eap_peap: [eaptls process] = ok
(11) eap_peap: Session established.  Decoding tunneled attributes
(11) eap_peap: PEAP state phase2
(11) eap_peap: EAP method MSCHAPv2 (26)
(11) eap_peap: Got tunneled request
(11) eap_peap:   EAP-Message = 0x020a00061a03
(11) eap_peap: Setting User-Name to test1.vpn
(11) eap_peap: Sending tunneled request to inner-tunnel
(11) eap_peap:   EAP-Message = 0x020a00061a03
(11) eap_peap:   FreeRADIUS-Proxied-To = 127.0.0.1
(11) eap_peap:   User-Name = "test1.vpn"
(11) eap_peap:   State = 0x77d61e8776dc0400aa8dafc0f122a1ae
(11) Virtual server inner-tunnel received request
(11)   EAP-Message = 0x020a00061a03
(11)   FreeRADIUS-Proxied-To = 127.0.0.1
(11)   User-Name = "test1.vpn"
(11)   State = 0x77d61e8776dc0400aa8dafc0f122a1ae
(11) WARNING: Outer and inner identities are the same.  User privacy is
compromised.
(11) server inner-tunnel {
(11)   session-state: No cached attributes
(11)   # Executing section authorize from file
/etc/raddb/sites-enabled/inner-tunnel
(11)     authorize {
(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 =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(11)           if ((&User-Name =~ /@/) && (&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)  = notfound
(11)       } # policy filter_username = notfound
(11)       [mschap] = noop
(11) eap: Peer sent EAP Response (code 2) ID 10 length 6
(11) eap: No EAP Start, assuming it's an on-going EAP conversation
(11)       [eap] = updated
(11)       [files] = noop
(11)       [expiration] = noop
(11)       [logintime] = noop
Not doing PAP as Auth-Type is already set.
(11)       [pap] = noop
(11)     } # authorize = updated
(11)   Found Auth-Type = eap
(11)   # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(11)     authenticate {
(11) eap: Expiring EAP session with state 0x77d61e8776dc0400
(11) eap: Finished EAP session with state 0x77d61e8776dc0400
(11) eap: Previous EAP request found for state 0x77d61e8776dc0400, released
from the list
(11) eap: Peer sent packet with method EAP MSCHAPv2 (26)
(11) eap: Calling submodule eap_mschapv2 to process data
(11) eap: Sending EAP Success (code 3) ID 10 length 4
(11) eap: Freeing handler
(11)       [eap] = ok
(11)     } # authenticate = ok
(11)   # Executing section post-auth from file
/etc/raddb/sites-enabled/inner-tunnel
(11)     post-auth {
(11)       update {
(11)         &outer.session-state::MS-MPPE-Encryption-Policy +=
&reply:MS-MPPE-Encryption-Policy[*] -> Encryption-Allowed
(11)         &outer.session-state::MS-MPPE-Encryption-Types +=
&reply:MS-MPPE-Encryption-Types[*] -> RC4-40or128-bit-Allowed
(11)         &outer.session-state::MS-MPPE-Send-Key +=
&reply:MS-MPPE-Send-Key[*] -> 0xc95e91e5d6d75a41ddedeb1d410b74dc
(11)         &outer.session-state::MS-MPPE-Recv-Key +=
&reply:MS-MPPE-Recv-Key[*] -> 0xf03d8d652f0906ecde38699a80de028f
(11)         &outer.session-state::EAP-Message += &reply:EAP-Message[*] ->
0x030a0004
(11)         &outer.session-state::Message-Authenticator +=
&reply:Message-Authenticator[*] -> 0x00000000000000000000000000000000
(11)         &outer.session-state::User-Name += &reply:User-Name[*] ->
'test1.vpn'
(11)       } # update = noop
(11)       update outer.session-state {
(11)         MS-MPPE-Encryption-Policy !* ANY
(11)         MS-MPPE-Encryption-Types !* ANY
(11)         MS-MPPE-Send-Key !* ANY
(11)         MS-MPPE-Recv-Key !* ANY
(11)         Message-Authenticator !* ANY
(11)         EAP-Message !* ANY
(11)         Proxy-State !* ANY
(11)       } # update outer.session-state = noop
(11)     } # post-auth = noop
(11) } # server inner-tunnel
(11) Virtual server sending reply
(11)   MS-MPPE-Encryption-Policy = Encryption-Allowed
(11)   MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed
(11)   MS-MPPE-Send-Key = 0xc95e91e5d6d75a41ddedeb1d410b74dc
(11)   MS-MPPE-Recv-Key = 0xf03d8d652f0906ecde38699a80de028f
(11)   EAP-Message = 0x030a0004
(11)   Message-Authenticator = 0x00000000000000000000000000000000
(11)   User-Name = "test1.vpn"
(11) eap_peap: Got tunneled reply code 2
(11) eap_peap:   MS-MPPE-Encryption-Policy = Encryption-Allowed
(11) eap_peap:   MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed
(11) eap_peap:   MS-MPPE-Send-Key = 0xc95e91e5d6d75a41ddedeb1d410b74dc
(11) eap_peap:   MS-MPPE-Recv-Key = 0xf03d8d652f0906ecde38699a80de028f
(11) eap_peap:   EAP-Message = 0x030a0004
(11) eap_peap:   Message-Authenticator = 0x00000000000000000000000000000000
(11) eap_peap:   User-Name = "test1.vpn"
(11) eap_peap: Got tunneled reply RADIUS code 2
(11) eap_peap:   MS-MPPE-Encryption-Policy = Encryption-Allowed
(11) eap_peap:   MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed
(11) eap_peap:   MS-MPPE-Send-Key = 0xc95e91e5d6d75a41ddedeb1d410b74dc
(11) eap_peap:   MS-MPPE-Recv-Key = 0xf03d8d652f0906ecde38699a80de028f
(11) eap_peap:   EAP-Message = 0x030a0004
(11) eap_peap:   Message-Authenticator = 0x00000000000000000000000000000000
(11) eap_peap:   User-Name = "test1.vpn"
(11) eap_peap: Tunneled authentication was successful
(11) eap_peap: SUCCESS
(11) eap: Sending EAP Request (code 1) ID 11 length 46
(11) eap: EAP session adding &reply:State = 0x1ee1c2c314eadbb6
(11)     [eap] = handled
(11)   } # authenticate = handled
(11) Using Post-Auth-Type Challenge
(11) Post-Auth-Type sub-section not found.  Ignoring.
(11) # Executing group from file /etc/raddb/sites-enabled/default
(11) session-state: Saving cached attributes
(11)   TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
(11)   TLS-Session-Version = "TLS 1.2"
(11)   User-Name += "test1.vpn"
(11) Sent Access-Challenge Id 120 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(11)   Framed-IP-Address = 10.10.10.6
(11)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(11)   Framed-IP-Netmask = 255.255.255.0
(11)   EAP-Message =
0x010b002e190017030300239e5cd13943bc51823fdd3ad50610c08ffcf4ce231dbd6edc1d417a43078e4963389339
(11)   Message-Authenticator = 0x00000000000000000000000000000000
(11)   State = 0x1ee1c2c314eadbb67da4e0496fb672ca
(11) Finished request
Waking up in 4.7 seconds.
(12) Received Access-Request Id 121 from 127.0.0.1:39643 to 127.0.0.1:1812
length 219
(12)   User-Name = "test1.vpn"
(12)   NAS-Port-Type = Virtual
(12)   Service-Type = Framed-User
(12)   NAS-Port = 23
(12)   NAS-Port-Id = "test1.vpn"
(12)   NAS-IP-Address = X.X.X.220
(12)   Called-Station-Id = "X.X.X.220[4500]"
(12)   Calling-Station-Id = "X.X.X.211[4500]"
(12)   Acct-Session-Id = "1654243660-23"
(12)   EAP-Message =
0x020b002e19001703030023000000000000000416d278d66d7f8798a444c0449219eac44a56f078d7d9eaa2278d64
(12)   NAS-Identifier = "strongSwan"
(12)   State = 0x1ee1c2c314eadbb67da4e0496fb672ca
(12)   Message-Authenticator = 0x397229ba90bc10f99d8795270a93e542
(12) Restoring &session-state
(12)   &session-state:TLS-Session-Cipher-Suite =
"ECDHE-RSA-AES256-GCM-SHA384"
(12)   &session-state:TLS-Session-Version = "TLS 1.2"
(12)   &session-state:User-Name += "test1.vpn"
(12) # Executing section authorize from file
/etc/raddb/sites-enabled/default
(12)   authorize {
(12) files: users: Matched entry test1.vpn at line 3
(12)     [files] = ok
(12)     [preprocess] = ok
(12)     [mschap] = noop
(12) eap: Peer sent EAP Response (code 2) ID 11 length 46
(12) eap: Continuing tunnel setup
(12)     [eap] = ok
(12)   } # authorize = ok
(12) Found Auth-Type = eap
(12) # Executing group from file /etc/raddb/sites-enabled/default
(12)   authenticate {
(12) eap: Expiring EAP session with state 0x1ee1c2c314eadbb6
(12) eap: Finished EAP session with state 0x1ee1c2c314eadbb6
(12) eap: Previous EAP request found for state 0x1ee1c2c314eadbb6, released
from the list
(12) eap: Peer sent packet with method EAP PEAP (25)
(12) eap: Calling submodule eap_peap to process data
(12) eap_peap: Continuing EAP-TLS
(12) eap_peap: [eaptls verify] = ok
(12) eap_peap: Done initial handshake
(12) eap_peap: [eaptls process] = ok
(12) eap_peap: Session established.  Decoding tunneled attributes
(12) eap_peap: PEAP state send tlv success
(12) eap_peap: Received EAP-TLV response
(12) eap_peap: Success
(12) eap: Sending EAP Success (code 3) ID 11 length 4
(12) eap: Freeing handler
(12)     [eap] = ok
(12)   } # authenticate = ok
(12) # Executing section post-auth from file
/etc/raddb/sites-enabled/default
(12)   post-auth {
(12) files: postauth_users: Matched entry test1.vpn at line 3
(12)     [files] = ok
(12)     policy remove_reply_message_if_eap {
(12)       if (&reply:EAP-Message && &reply:Reply-Message) {
(12)       if (&reply:EAP-Message && &reply:Reply-Message)  -> FALSE
(12)       else {
(12)         [noop] = noop
(12)       } # else = noop
(12)     } # policy remove_reply_message_if_eap = noop
(12)     policy insert_acct_class {
(12)       update reply {
(12)         EXPAND
ai:%{md5:%t,%I,%{Packet-Src-Port},%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}},%{NAS-IP-Address},%{Calling-Station-ID},%{User-Name}}
(12)            --> ai:e32f591f5372c47a6a9a75e86e6ff479
(12)         &Class =
0x61693a6533326635393166353337326334376136613961373565383665366666343739
(12)       } # update reply = noop
(12)     } # policy insert_acct_class = noop
(12)   } # post-auth = ok
(12) Sent Access-Accept Id 121 from 127.0.0.1:1812 to 127.0.0.1:39643
length 0
(12)   Framed-IP-Address = 10.10.10.6
(12)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(12)   Framed-IP-Netmask = 255.255.255.0
(12)   MS-MPPE-Recv-Key =
0xd06fc9235d3e1bd45c16b64e88bae2f24f7827762e3039aa2c5ce5a0e71ab007
(12)   MS-MPPE-Send-Key =
0xe228cae63f7c4328f95359e408fcd2cbebd6d7a7ec99129f458e08aca4e755dc
(12)   EAP-Message = 0x030b0004
(12)   Message-Authenticator = 0x00000000000000000000000000000000
(12)   User-Name = "test1.vpn"
(12)   Framed-IP-Address = 10.10.10.6
(12)   Framed-Route = "172.16.10.0/24 172.16.10.254"
(12)   Framed-IP-Netmask = 255.255.255.0
(12)   Class =
0x61693a6533326635393166353337326334376136613961373565383665366666343739
(12) Finished request
Waking up in 4.7 seconds.
(13) Received Accounting-Request Id 122 from 127.0.0.1:36435 to
127.0.0.1:1813 length 147
(13)   Acct-Status-Type = Start
(13)   Acct-Session-Id = "1654243660-23"
(13)   NAS-Port-Type = Virtual
(13)   Service-Type = Framed-User
(13)   NAS-Port = 23
(13)   NAS-Port-Id = "test1.vpn"
(13)   NAS-IP-Address = X.X.X.220
(13)   Called-Station-Id = "X.X.X.220[4500]"
(13)   Calling-Station-Id = "X.X.X.211[4500]"
(13)   User-Name = "test1.vpn"
(13)   Framed-IP-Address = 10.10.10.6
(13)   NAS-Identifier = "strongSwan"
(13) # Executing section preacct from file /etc/raddb/sites-enabled/default
(13)   preacct {
(13)     [files] = noop
(13)     [preprocess] = ok
(13)     policy acct_unique {
(13)       update request {
(13)         &Tmp-String-9 := "ai:"
(13)       } # update request = noop
(13)       if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&
 ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i)) {
(13)       EXPAND %{hex:&Class}
(13)          -->
(13)       EXPAND ^%{hex:&Tmp-String-9}
(13)          --> ^61693a
(13)       if (("%{hex:&Class}" =~ /^%{hex:&Tmp-String-9}/) &&
 ("%{string:&Class}" =~ /^ai:([0-9a-f]{32})/i))  -> FALSE
(13)       else {
(13)         update request {
(13)           EXPAND
%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(13)              --> 4d5814ca5bc08a27b81676d0ab0f9f3e
(13)           &Acct-Unique-Session-Id := 4d5814ca5bc08a27b81676d0ab0f9f3e
(13)         } # update request = noop
(13)       } # else = noop
(13)     } # policy acct_unique = noop
(13)   } # preacct = ok
(13) # Executing section accounting from file
/etc/raddb/sites-enabled/default
(13)   accounting {
(13) attr_filter.accounting_response: EXPAND %{User-Name}
(13) attr_filter.accounting_response:    --> test1.vpn
(13) attr_filter.accounting_response: Matched entry DEFAULT at line 12
(13)     [attr_filter.accounting_response] = updated
(13)   } # accounting = updated
(13) Sent Accounting-Response Id 122 from 127.0.0.1:1813 to 127.0.0.1:36435
length 0
(13) Finished request
(13) Cleaning up request packet ID 122 with timestamp +147

At the twelve packet we can clearly see the framed IP route and even
before. It is seen in the Access-Accept packet but not in the
Accouting-Request.
My guess is that i am missing an option in the sites-enabled/default. I
remembered about my issue with the option use_tunneled_yes so I put the two
update block at the post-auth part of the inner tunnel by following this
doc :
https://networkradius.com/doc/3.0.10/raddb/sites-available/inner-tunnel.html.
It may be irrelevant to the issue.

Thanks in advance for any tips or lead,
Best regards.

Alexis Lacoste

Alan DeKok

tags

participants (2)