I'm running FreeRADIUS 2.1.1. My config block in the post-auth section of the inner-tunnel server currently reads: update outer.reply { User-Name := "testing-%{User-Name}" } FR does indeed appear to be using this block: expand: testing-%{User-Name} -> testing-jg4461 ++[outer.reply] returns ok Authenticating with outer ID "qwerty99" and inner ID "jg4461" gives output as in the attached log, included to give context. The outer server is "uobresnet" and the inner one is still called "inner-tunnel". So it seems to me like FR is doing what it is being asked to do, but maybe this isn't the right thing. Previous tests showed that setting the outer ID in the "uobresnet" server does make the NAS use the right username. If anyone can shed any light on this, I'd be very grateful. Thanks, Jonathan Alan DeKok wrote:
Jonathan Gazeley wrote:
When added in the "inner-tunnel" server, this block has no effect on the content of the Access-Accept packets (as shown by radiusd -X).
Which version are you running? Is it *using* that entry you added?
Alan DeKok.
rad_recv: Access-Request packet from host 172.17.107.241 port 32770, id=48, length=183 User-Name = "qwerty99" Calling-Station-Id = "00-15-AF-CB-1E-27" Called-Station-Id = "00-16-C7-71-A1-20:ResNet-Wireless" NAS-Port = 29 NAS-IP-Address = 172.17.107.241 NAS-Identifier = "wism1" Airespace-Wlan-Id = 7 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "509" EAP-Message = 0x0202000d017177657274793939 Message-Authenticator = 0xa489b89767d25a5321fb294fe2bb7318 server uobresnet { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] expand: %t -> Fri Jan 30 14:17:14 2009 ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "qwerty99", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 2 length 13 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [files] users: Matched entry DEFAULT at line 180 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. ++[pap] returns noop Found Auth-Type = EAP +- entering group authenticate {...} [eap] EAP Identity [eap] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap] returns handled } # server uobresnet Sending Access-Challenge of id 48 to 172.17.107.241 port 32770 Acct-Interim-Interval = 600 EAP-Message = 0x010300061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xbcf702b7bcf4177cb8f89cfa1efb626b Finished request 0. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 172.17.107.241 port 32770, id=49, length=305 User-Name = "qwerty99" Calling-Station-Id = "00-15-AF-CB-1E-27" Called-Station-Id = "00-16-C7-71-A1-20:ResNet-Wireless" NAS-Port = 29 NAS-IP-Address = 172.17.107.241 NAS-Identifier = "wism1" Airespace-Wlan-Id = 7 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "509" EAP-Message = 0x020300751500160301006a01000066030149830beb875a869d3a0ba0a3871ee2aeea4c4299fdfdb5a89e0eb387d459039a00003800390038003500880087008400160013000a00330032002f009a009900960045004400410005000400150012000900140011000800060003020100000400230000 State = 0xbcf702b7bcf4177cb8f89cfa1efb626b Message-Authenticator = 0xcc68643b3b3e55b15ed6b5a9428f1631 server uobresnet { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] expand: %t -> Fri Jan 30 14:17:14 2009 ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "qwerty99", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 3 length 117 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] eaptls_verify returned 7 [ttls] Done initial handshake [ttls] (other): before/accept initialization [ttls] TLS_accept: before/accept initialization [ttls] <<< TLS 1.0 Handshake [length 006a], ClientHello [ttls] TLS_accept: SSLv3 read client hello A [ttls] >>> TLS 1.0 Handshake [length 002a], ServerHello [ttls] TLS_accept: SSLv3 write server hello A [ttls] >>> TLS 1.0 Handshake [length 08c3], Certificate [ttls] TLS_accept: SSLv3 write certificate A [ttls] >>> TLS 1.0 Handshake [length 018d], ServerKeyExchange [ttls] TLS_accept: SSLv3 write key exchange A [ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [ttls] TLS_accept: SSLv3 write server done A [ttls] TLS_accept: SSLv3 flush data [ttls] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [ttls] eaptls_process returned 13 ++[eap] returns handled } # server uobresnet Sending Access-Challenge of id 49 to 172.17.107.241 port 32770 EAP-Message = 0x0104040015c000000a92160301002a02000026030149830bea6b4fa677b93955dbbb4433acd6a14a2ff2c8b554e7c970e3e3366bd40000390116030108c30b0008bf0008bc0004703082046c30820354a003020102020b0100000000011dabb77cbd300d06092a864886f70d0101050500305f310b300906035504061302424531133011060355040a130a4379626572747275737431173015060355040b130e456475636174696f6e616c20434131223020060355040313194379626572747275737420456475636174696f6e616c204341301e170d3038313131373137323730395a170d3131313131373137323730395a308191310b300906035504 EAP-Message = 0x0613024742310d300b0603550408130441766f6e3110300e0603550407130742726973746f6c311e301c060355040a1315556e6976657273697479206f662042726973746f6c311d301b060355040b1314496e666f726d6174696f6e20536572766963657331223020060355040313196d6f6368612e776972656c6573732e627269732e61632e756b30819f300d06092a864886f70d010101050003818d0030818902818100e914727ed8c9b31fc5bf672132b5e924f7b09ad0ef3dfd10991c26bf1f4cf023c5508a399d3128b119847524d3ee190af855e4f30430199cf867800798287e91f88bce6609bb6f262ba2759bfcb160187076b3eb39f559 EAP-Message = 0x41c6778ec596a583508cc3e747a01c85d29b37b321e782fb6431a84dca6aaf36baf1f8acf3455bfc810203010001a38201783082017430500603551d2004493047304506072a8648b13e0100303a303806082b06010505070201162c687474703a2f2f7777772e676c6f62616c7369676e2e6e65742f7265706f7369746f72792f6370732e63666d300e0603551d0f0101ff0404030205a0301f0603551d230418301680146565a33dd73b11a30a072537c9424a5b767750e1301d0603551d0e0416041480a8a90697105d00450f52fa07845747f3306b76303a0603551d1f04333031302fa02da02b8629687474703a2f2f63726c2e676c6f62616c73 EAP-Message = 0x69676e2e6e65742f656475636174696f6e616c2e63726c304f06082b0601050507010104433041303f06082b060105050730028633687474703a2f2f7365637572652e676c6f62616c7369676e2e6e65742f6361636572742f656475636174696f6e616c2e637274301d0603551d250416301406082b0601050507030106082b0601050507030230240603551d11041d301b82196d6f6368612e776972656c6573732e627269732e61632e756b300d06092a864886f70d01010505000382010100445e685356ac0bc673e60526f9b76a38f97090ad7839fc39b40c3fc0a1e56f9a15020b574237761b6d3b23cdc929e0beeffa25e47d9282125a5d9c34 EAP-Message = 0xc451b0aaa2c0dc33fe3842ed Message-Authenticator = 0x00000000000000000000000000000000 State = 0xbcf702b7bdf3177cb8f89cfa1efb626b Finished request 1. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 172.17.107.241 port 32770, id=50, length=194 User-Name = "qwerty99" Calling-Station-Id = "00-15-AF-CB-1E-27" Called-Station-Id = "00-16-C7-71-A1-20:ResNet-Wireless" NAS-Port = 29 NAS-IP-Address = 172.17.107.241 NAS-Identifier = "wism1" Airespace-Wlan-Id = 7 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "509" EAP-Message = 0x020400061500 State = 0xbcf702b7bdf3177cb8f89cfa1efb626b Message-Authenticator = 0x169415cf461a620510aedc38f1959105 server uobresnet { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] expand: %t -> Fri Jan 30 14:17:14 2009 ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "qwerty99", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 4 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] Received TLS ACK [ttls] ACK handshake fragment handler [ttls] eaptls_verify returned 1 [ttls] eaptls_process returned 13 ++[eap] returns handled } # server uobresnet Sending Access-Challenge of id 50 to 172.17.107.241 port 32770 EAP-Message = 0x0105040015c000000a92d9764c6bf0b24aaa7495ffdf2473e1f92f6bed91b0f76e25d2ca0dcaef60ce08695940ed4e955fb566250ef44439c7a407ca6bdf088dfd3183a99501f2f4d60b1d143e36ac34814b5a37debe46224e910e78d6f6702a7af83fd4efb2b287fdf039f279a9f53099c7f3f8b252df49a7530e4bb6a0faab5714d98090fd13f004d202ba4cd242f871ebdb165dd40af95fb42ba17fba6c97b18833df3fc8230fe4e5ed1e6f60043707aef2f9ab1d4c8eb5ad332c58a955a9169600044630820442308203aba0030201020204040003fb300d06092a864886f70d01010505003075310b300906035504061302555331183016060355 EAP-Message = 0x040a130f47544520436f72706f726174696f6e31273025060355040b131e475445204379626572547275737420536f6c7574696f6e732c20496e632e312330210603550403131a475445204379626572547275737420476c6f62616c20526f6f74301e170d3036303331343230333030305a170d3133303331343233353930305a305f310b300906035504061302424531133011060355040a130a4379626572747275737431173015060355040b130e456475636174696f6e616c20434131223020060355040313194379626572747275737420456475636174696f6e616c20434130820122300d06092a864886f70d01010105000382010f00308201 EAP-Message = 0x0a02820101009522a1101d4a46606e05919bdf83c2ed12b25a7cf8abe1f8505c282c7e7e003893b08b4af1c24c3c102c3cefb0eca1692fb9fccc08146b8d4f18f383d2faa9370820aa5caa8060a2d5a52200cf5ae5b497dfba1ebe5c8e171966fdaf9f7c7b89b20e24d8c7ab63c495328d48e663597d04b833a8bdd75d64bc63b5f74d28fdf90672315cba459465a3d2b458ec3b615844a32f62b39b80b482fdd5c7cc5125e5953f472f307bacc8786ee2e16d27eb3dcc0182e835778dab58bb55d1d5a481568d1cd014b1b006dea09122f3f0a8341747c6e03ef60c5aac7e504bcde1696e06fc067e6a4db49599a0595c3566ecd949d417e060b05da5 EAP-Message = 0xd71ae22a6e66f2af1d0203010001a382016f3082016b30450603551d1f043e303c303aa038a0368634687474703a2f2f7777772e7075626c69632d74727573742e636f6d2f6367692d62696e2f43524c2f323031382f6364702e63726c301d0603551d0e041604146565a33dd73b11a30a072537c9424a5b767750e130530603551d20044c304a304806092b06010401b13e0100303b303906082b06010505070201162d687474703a2f2f7777772e7075626c69632d74727573742e636f6d2f4350532f4f6d6e69526f6f742e68746d6c3081890603551d23048181307fa179a4773075310b300906035504061302555331183016060355040a130f47 EAP-Message = 0x544520436f72706f72617469 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xbcf702b7bef2177cb8f89cfa1efb626b Finished request 2. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 172.17.107.241 port 32770, id=51, length=194 User-Name = "qwerty99" Calling-Station-Id = "00-15-AF-CB-1E-27" Called-Station-Id = "00-16-C7-71-A1-20:ResNet-Wireless" NAS-Port = 29 NAS-IP-Address = 172.17.107.241 NAS-Identifier = "wism1" Airespace-Wlan-Id = 7 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "509" EAP-Message = 0x020500061500 State = 0xbcf702b7bef2177cb8f89cfa1efb626b Message-Authenticator = 0x71d3de51a235ec70c0fdcf3ab04f6905 server uobresnet { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] expand: %t -> Fri Jan 30 14:17:14 2009 ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "qwerty99", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 5 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] Received TLS ACK [ttls] ACK handshake fragment handler [ttls] eaptls_verify returned 1 [ttls] eaptls_process returned 13 ++[eap] returns handled } # server uobresnet Sending Access-Challenge of id 51 to 172.17.107.241 port 32770 EAP-Message = 0x010602b0158000000a926f6e31273025060355040b131e475445204379626572547275737420536f6c7574696f6e732c20496e632e312330210603550403131a475445204379626572547275737420476c6f62616c20526f6f74820201a5300e0603551d0f0101ff04040302010630120603551d130101ff040830060101ff020100300d06092a864886f70d01010505000381810043b345835471c41fdcb23c6b4ebf26f24ef2ad9a5bfa863788e8146c4118425fef653eeb0377a0b79e757a517cbb155bb8af91a0349253ed7f2a4984acb9804bb5c7b22322fbebd8fb6ec93cf3d2d1bbbec91cff6d01db69800e99a5ea9e7b97988fb7cf229cb3b8 EAP-Message = 0x5de5a9331774c697370fb4e926825f610b3f1e3d64e92b9b160301018d0c00018900809115795209b26f52b0d229ac083b55262c8f5eaed97d69a711e9a02419cfe778b492ff5eaf285dda5066ec10837864e8784386171fe26862865661597b99f569363efd47b100c8fac1cb58af75cac756ee30c2f3a1fcb080f12f3294a224a91f4525e6fee049efb559c4a1b2d946cfdaaac3060f85e9da753d4d89da4d653703000102008085922c80e39fe745337c29845c7e77de8ced285d10d201f5a0f39eeb69ced596022e8b499646d3287e91a8eb25adea9b3f22d1a29d170ea6dcec777bb4b6304c9b8c22a31debb4c7d4ab37034a0a100a0f60d18cd7 EAP-Message = 0x497471a86464c63753cf2668d9e3894912010d79ca103d49ecaec872a0e321d0ef1cfb4566b3a90cfa98db0080dc50cfd8b1e1aefd134b5553dc999f1b705cf3ff45cdaa2da9f19876939dbbffaec6bbf6609edb4a415e50561f2750624feb9f06ad2e374f413f8821cbc23f2dcf8f8b01c25f484d208b8b180f5cf402f9520e5959b86febf01de00a6b4824d267e93b6e1e696210608c39c43601f7c8776017b9e99b2e8d174af76789edb3e716030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xbcf702b7bff1177cb8f89cfa1efb626b Finished request 3. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 172.17.107.241 port 32770, id=52, length=392 User-Name = "qwerty99" Calling-Station-Id = "00-15-AF-CB-1E-27" Called-Station-Id = "00-16-C7-71-A1-20:ResNet-Wireless" NAS-Port = 29 NAS-IP-Address = 172.17.107.241 NAS-Identifier = "wism1" Airespace-Wlan-Id = 7 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "509" EAP-Message = 0x020600cc15001603010086100000820080370149359d6c857223606b10e116f7ba7d86d3e3e3039e85a9d8559ba2ea4999ec6d3b75ef8d56213458c222d4af6aeedd3901a44642888646c5d416af58dc6dc261856b18dd24dca05050b8a0a26cdc7220ce9bd1ad705b80b8de947f5ee50b2a0d8a6cb0eaba73bdd33cdf7623b6f61802d8258191baff38572434b95649e014030100010116030100309487cb09df80fbf86fdc8c082001a74ef8d9b89e0d55853378b5275ee27775dabbdb09efbedb9575fd27e33ab8926185 State = 0xbcf702b7bff1177cb8f89cfa1efb626b Message-Authenticator = 0x60565907ca976c522c29461ff6c035ec server uobresnet { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] expand: %t -> Fri Jan 30 14:17:14 2009 ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "qwerty99", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 6 length 204 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] eaptls_verify returned 7 [ttls] Done initial handshake [ttls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange [ttls] TLS_accept: SSLv3 read client key exchange A [ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001] [ttls] <<< TLS 1.0 Handshake [length 0010], Finished [ttls] TLS_accept: SSLv3 read finished A [ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001] [ttls] TLS_accept: SSLv3 write change cipher spec A [ttls] >>> TLS 1.0 Handshake [length 0010], Finished [ttls] TLS_accept: SSLv3 write finished A [ttls] TLS_accept: SSLv3 flush data [ttls] (other): SSL negotiation finished successfully SSL Connection Established [ttls] eaptls_process returned 13 ++[eap] returns handled } # server uobresnet Sending Access-Challenge of id 52 to 172.17.107.241 port 32770 EAP-Message = 0x0107004515800000003b1403010001011603010030bfa10ca56759ae796dd555e890a53f0a2bec41cf951ce69619920a30210ceba6a0ae75a1303ec48737ded4aa981b5c03 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xbcf702b7b8f0177cb8f89cfa1efb626b Finished request 4. Going to the next request Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 172.17.107.241 port 32770, id=53, length=364 User-Name = "qwerty99" Calling-Station-Id = "00-15-AF-CB-1E-27" Called-Station-Id = "00-16-C7-71-A1-20:ResNet-Wireless" NAS-Port = 29 NAS-IP-Address = 172.17.107.241 NAS-Identifier = "wism1" Airespace-Wlan-Id = 7 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "509" EAP-Message = 0x020700b015001703010020b442254fcbb3e0db440ef2851f3a1f0bf38c0d04d1e820c4eb9645b5aea6fb5517030100807df19efbe437f2a4e1a2c3f70d2b2ce2e06ba8a845a8943224987a5381315a805a7f2bd12853ef6d92809e5d27d1abf4b1a0444d28e0826a304d17c868157cf75fffc4b3b3ebfb74c5133dbb9e38e7289ff5438c6cc324231c0a917f7c7c685fdd4489406f97ac80387e562336f89eb35706ac56eeec77e779a939f7430a0f30 State = 0xbcf702b7b8f0177cb8f89cfa1efb626b Message-Authenticator = 0x551597ad43c56909f6cc5934b414a9bb server uobresnet { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] expand: %t -> Fri Jan 30 14:17:14 2009 ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "qwerty99", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 7 length 176 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] eaptls_verify returned 7 [ttls] Done initial handshake [ttls] eaptls_process returned 7 [ttls] Session established. Proceeding to decode tunneled attributes. [ttls] Got tunneled request User-Name = "jg4461" MS-CHAP-Challenge = 0xff305fa4db71a85589d826790108164c MS-CHAP2-Response = 0xc60000000019000000902b8b08782b8b08020000000000000000b9409779258898d6d2267f38ce4bcf122ac4c15decc186ad FreeRADIUS-Proxied-To = 127.0.0.1 [ttls] Sending tunneled request User-Name = "jg4461" MS-CHAP-Challenge = 0xff305fa4db71a85589d826790108164c MS-CHAP2-Response = 0xc60000000019000000902b8b08782b8b08020000000000000000b9409779258898d6d2267f38ce4bcf122ac4c15decc186ad FreeRADIUS-Proxied-To = 127.0.0.1 server inner-tunnel { +- entering group authorize {...} [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] returns ok [suffix] No '@' in User-Name = "jg4461", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop [files] users: Matched entry DEFAULT at line 180 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop ++? if ("%{User-Name}") expand: %{User-Name} -> jg4461 ? Evaluating ("%{User-Name}") -> TRUE ++? if ("%{User-Name}") -> TRUE ++- entering if ("%{User-Name}") {...} +++? if (`/usr/local/etc/raddb/scripts/UserLookup.pl %{User-Name}`) expand: %{User-Name} -> jg4461 Exec-Program output: 0 Exec-Program-Wait: plaintext: 0 Exec-Program: returned: 0 ? Evaluating (`/usr/local/etc/raddb/scripts/UserLookup.pl %{User-Name}`) -> FALSE +++? if (`/usr/local/etc/raddb/scripts/UserLookup.pl %{User-Name}`) -> FALSE ++- if ("%{User-Name}") returns noop [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. ++[pap] returns noop Found Auth-Type = MSCHAP +- entering group MS-CHAP {...} [mschap] No Cleartext-Password configured. Cannot create LM-Password. [mschap] No Cleartext-Password configured. Cannot create NT-Password. [mschap] Told to do MS-CHAPv2 for jg4461 with NT-Password [mschap] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [mschap] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [mschap] expand: --username=%{Stripped-User-Name:-%{User-Name:-None}} -> --username=jg4461 [mschap] mschap2: ff [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=6dba8e6684f35989 [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=b9409779258898d6d2267f38ce4bcf122ac4c15decc186ad Exec-Program output: NT_KEY: D86E6EA7E8BF7B443494C45046862DAE Exec-Program-Wait: plaintext: NT_KEY: D86E6EA7E8BF7B443494C45046862DAE Exec-Program: returned: 0 [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok Login OK: [jg4461] (from client WISM-1 port 0 via TLS tunnel) +- entering group post-auth {...} [sql] expand: %{User-Name} -> jg4461 [sql] sql_set_user escaped user --> 'jg4461' [sql] expand: %{User-Password} -> [sql] expand: %{Chap-Password} -> [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 ( 'jg4461', '', 'Access-Accept', '2009-01-30 14:17:14') rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'jg4461', '', 'Access-Accept', '2009-01-30 14:17:14') rlm_sql (sql): Reserving sql socket id: 4 rlm_sql (sql): Released sql socket id: 4 ++[sql] returns ok expand: testing-%{User-Name} -> testing-jg4461 ++[outer.reply] returns ok } # server inner-tunnel [ttls] Got tunneled reply code 2 Acct-Interim-Interval = 600 MS-CHAP2-Success = 0xc6533d31363536303839313843323532353646444136354443373842413045303539414243344246304245 MS-MPPE-Recv-Key = 0x01ad9a928819149b915d883998666ced MS-MPPE-Send-Key = 0xaa00c20e66cbc3d2f567156c45951213 MS-MPPE-Encryption-Policy = 0x00000002 MS-MPPE-Encryption-Types = 0x00000004 [ttls] Got tunneled Access-Accept [ttls] Got MS-CHAP2-Success, tunneling it to the client in a challenge. ++[eap] returns handled } # server uobresnet Sending Access-Challenge of id 53 to 172.17.107.241 port 32770 User-Name = "testing-jg4461" EAP-Message = 0x0108006f15800000006517030100601459597525dce210c76ca3af6be2abd4f34223a646eca34174e85dbce65b050d78886acfffc2cbb93d85ed197cbaa5eca006c6ece7a2be50dda8da09f3d53f07f2052992c83c9c2137947309dfc7e0957bbba8ee8c85637fea4d555848836051 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xbcf702b7b9ff177cb8f89cfa1efb626b Finished request 5. Going to the next request Waking up in 4.5 seconds. rad_recv: Access-Request packet from host 172.17.107.241 port 32770, id=54, length=194 User-Name = "qwerty99" Calling-Station-Id = "00-15-AF-CB-1E-27" Called-Station-Id = "00-16-C7-71-A1-20:ResNet-Wireless" NAS-Port = 29 NAS-IP-Address = 172.17.107.241 NAS-Identifier = "wism1" Airespace-Wlan-Id = 7 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "509" EAP-Message = 0x020800061500 State = 0xbcf702b7b9ff177cb8f89cfa1efb626b Message-Authenticator = 0x9901c773af1b971e6c4935c5d4ff3771 server uobresnet { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/172.17.107.241/auth-detail-20090130 [auth_log] expand: %t -> Fri Jan 30 14:17:15 2009 ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "qwerty99", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 8 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/ttls [eap] processing type ttls [ttls] Authenticate [ttls] processing EAP-TLS [ttls] Received TLS ACK [ttls] ACK handshake is finished [ttls] eaptls_verify returned 3 [ttls] eaptls_process returned 3 [eap] Freeing handler ++[eap] returns ok Login OK: [qwerty99] (from client WISM-1 port 29 cli 00-15-AF-CB-1E-27) +- entering group post-auth {...} [reply_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d -> /var/log/radius/radacct/172.17.107.241/reply-detail-20090130 [reply_log] /var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/radius/radacct/172.17.107.241/reply-detail-20090130 [reply_log] expand: %t -> Fri Jan 30 14:17:15 2009 ++[reply_log] returns ok } # server uobresnet Sending Access-Accept of id 54 to 172.17.107.241 port 32770 MS-MPPE-Recv-Key = 0x005bd32b2a84548ef088a3ee03c6f9233b36144482a9afe5362dca38a1c14375 MS-MPPE-Send-Key = 0xf3f6604a42101ab41c49dc9e38bfc53eb0aef67786d7e90e97b6a950c82ab809 EAP-Message = 0x03080004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "qwerty99" Finished request 6. Going to the next request Waking up in 4.5 seconds. rad_recv: Accounting-Request packet from host 172.17.107.241 port 32770, id=97, length=158 User-Name = "qwerty99" NAS-Port = 29 NAS-IP-Address = 172.17.107.241 Framed-IP-Address = 172.21.111.3 NAS-Identifier = "wism1" Airespace-Wlan-Id = 7 Acct-Session-Id = "49830bec/00:15:af:cb:1e:27/472" Acct-Authentic = RADIUS Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "509" Acct-Status-Type = Start Calling-Station-Id = "172.21.111.3" Called-Station-Id = "172.17.107.241" server uobresnet { +- entering group preacct {...} ++[preprocess] returns ok [acct_unique] Hashing 'NAS-Port = 29,Client-IP-Address = 172.17.107.241,NAS-IP-Address = 172.17.107.241,Acct-Session-Id = "49830bec/00:15:af:cb:1e:27/472",User-Name = "qwerty99"' [acct_unique] Acct-Unique-Session-ID = "ccc508efc405ffa0". ++[acct_unique] returns ok [suffix] No '@' in User-Name = "qwerty99", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop ++[files] returns noop +- entering group accounting {...} [detail] expand: /var/log/radius/radacct/%Y%m/detail-%Y%m%d -> /var/log/radius/radacct/200901/detail-20090130 [detail] /var/log/radius/radacct/%Y%m/detail-%Y%m%d expands to /var/log/radius/radacct/200901/detail-20090130 [detail] expand: %t -> Fri Jan 30 14:17:17 2009 ++[detail] returns ok [sql] expand: %{User-Name} -> qwerty99 [sql] sql_set_user escaped user --> 'qwerty99' [sql] expand: %{Acct-Delay-Time} -> [sql] expand: INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey, radius_server, ssid) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', '0', '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Proto rlm_sql (sql): Reserving sql socket id: 3 rlm_sql (sql): Released sql socket id: 3 ++[sql] returns ok [attr_filter.accounting_response] expand: %{User-Name} -> qwerty99 attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated } # server uobresnet Sending Accounting-Response of id 97 to 172.17.107.241 port 32770 Finished request 7. Cleaning up request 7 ID 97 with timestamp +16 Going to the next request Waking up in 2.5 seconds. rad_recv: Access-Request packet from host 172.17.107.248 port 32770, id=131, length=181 User-Name = "0019c5357751" Called-Station-Id = "00-1c-57-e2-2f-b0:ResNet-Wireless-Consoles" Calling-Station-Id = "00-19-c5-35-77-51" NAS-Port = 29 NAS-IP-Address = 172.17.107.248 NAS-Identifier = "wism8" Airespace-Wlan-Id = 2 User-Password = "0019c5357751" Service-Type = Call-Check Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 Tunnel-Type:0 = VLAN Tunnel-Medium-Type:0 = IEEE-802 Tunnel-Private-Group-Id:0 = "495" server uobconsoles { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/radius/radacct/172.17.107.248/auth-detail-20090130 [auth_log] /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/172.17.107.248/auth-detail-20090130 [auth_log] expand: %t -> Fri Jan 30 14:17:18 2009 ++[auth_log] returns ok perl_pool: item 0x8e13fe8 asigned new request. Handled so far: 1 found interpetator at address 0x8e13fe8 rlm_perl: Added pair NAS-Port-Type = Wireless-802.11 rlm_perl: Added pair Service-Type = Call-Check rlm_perl: Added pair Tunnel-Medium-Type = IEEE-802 rlm_perl: Added pair Tunnel-Type = VLAN rlm_perl: Added pair Calling-Station-Id = 00-19-c5-35-77-51 rlm_perl: Added pair Called-Station-Id = 00-1c-57-e2-2f-b0:ResNet-Wireless-Consoles rlm_perl: Added pair Airespace-Wlan-Id = 2 rlm_perl: Added pair User-Name = 0019c5357751 rlm_perl: Added pair NAS-Identifier = wism8 rlm_perl: Added pair User-Password = 0019c5357751 rlm_perl: Added pair NAS-Port = 29 rlm_perl: Added pair NAS-IP-Address = 172.17.107.248 rlm_perl: Added pair Tunnel-Private-Group-Id = 495 rlm_perl: Added pair Framed-MTU = 1300 perl_pool total/active/spare [32/0/32] Unreserve perl at address 0x8e13fe8 ++[perl] returns noop ++[control] returns noop ++[mschap] returns noop [suffix] No '@' in User-Name = "0019c5357751", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop [files] users: Matched entry DEFAULT at line 180 ++[files] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING! No "known good" password found for the user. Authentication may fail because of this. ++[pap] returns noop Found Auth-Type = PERL +- entering group PERL {...} perl_pool: item 0x9043928 asigned new request. Handled so far: 1 found interpetator at address 0x9043928 rlm_perl: Added pair NAS-Port-Type = Wireless-802.11 rlm_perl: Added pair Service-Type = Call-Check rlm_perl: Added pair Tunnel-Type = VLAN rlm_perl: Added pair Tunnel-Medium-Type = IEEE-802 rlm_perl: Added pair Called-Station-Id = 00-1c-57-e2-2f-b0:ResNet-Wireless-Consoles rlm_perl: Added pair Calling-Station-Id = 00-19-c5-35-77-51 rlm_perl: Added pair Airespace-Wlan-Id = 2 rlm_perl: Added pair User-Name = 0019c5357751 rlm_perl: Added pair NAS-Identifier = wism8 rlm_perl: Added pair User-Password = 0019c5357751 rlm_perl: Added pair NAS-IP-Address = 172.17.107.248 rlm_perl: Added pair NAS-Port = 29 rlm_perl: Added pair Framed-MTU = 1300 rlm_perl: Added pair Tunnel-Private-Group-Id = 495 rlm_perl: Added pair Acct-Interim-Interval = 600 rlm_perl: Added pair Auth-Type = PERL perl_pool total/active/spare [32/0/32] Unreserve perl at address 0x9043928 ++[perl] returns ok Login OK: [0019c5357751] (from client WISM-8 port 29 cli 00-19-c5-35-77-51) +- entering group post-auth {...} [reply_log] expand: /var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d -> /var/log/radius/radacct/172.17.107.248/reply-detail-20090130 [reply_log] /var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/radius/radacct/172.17.107.248/reply-detail-20090130 [reply_log] expand: %t -> Fri Jan 30 14:17:18 2009 ++[reply_log] returns ok } # server uobconsoles Sending Access-Accept of id 131 to 172.17.107.248 port 32770 Acct-Interim-Interval = 600 Finished request 8. Going to the next request Waking up in 1.1 seconds. Cleaning up request 0 ID 48 with timestamp +13 Cleaning up request 1 ID 49 with timestamp +13 Cleaning up request 2 ID 50 with timestamp +13 Cleaning up request 3 ID 51 with timestamp +13 Waking up in 0.1 seconds. Cleaning up request 4 ID 52 with timestamp +13 Waking up in 0.3 seconds. Cleaning up request 5 ID 53 with timestamp +13 Cleaning up request 6 ID 54 with timestamp +14 Waking up in 3.3 seconds.