Hi Matthew,
If my memory serves correctly there was something with copy request to tunnel that was fixed recently. But I might have mis-remembered. Try 3.0.11 (or 3.0.x).
The changelog for 3.0.8 shows "Fix copy_request_to_tunnel issues for tagged attributes." as bugfix. But 3.0.10 would have this fix. I tried 3.0.11 but with the exact same results. I put the full request log with 3.0.11 at the end of the mail for reference.
But &outer.request:... should be fine here.
Yup, seems to work fine so I'll stick with that for now. Cheers, Sylvain (8) Received Access-Request Id 50 from 192.168.1.237:1645 to 192.168.1.1:1812 length 195 (8) User-Name = "pwd1" (8) Framed-MTU = 1400 (8) Called-Station-Id = "0000.0000.0000" (8) Calling-Station-Id = "0000.0000.0000" (8) Cisco-AVPair = "ssid=TestMain" (8) Service-Type = Login-User (8) Message-Authenticator = 0x0ab950b182f03feef9d95e73cf4ad55c (8) EAP-Message = 0x0209002b190017030100202bf0918ac6a9599c50ea424017c1b908b9e9e593fb9e7ed474a350f8920d61d9 (8) NAS-Port-Type = Wireless-802.11 (8) NAS-Port = 591 (8) NAS-Port-Id = "591" (8) State = 0x15a90c2012a015839a62d961a44b0787 (8) NAS-IP-Address = 192.168.1.237 (8) session-state: No cached attributes (8) # Executing section authorize from file /tmp/we/radius/_root/etc/raddb/sites-enabled/default (8) authorize { (8) policy filter_username { (8) if (!&User-Name) { (8) if (!&User-Name) -> FALSE (8) if (&User-Name =~ / /) { (8) if (&User-Name =~ / /) -> FALSE (8) if (&User-Name =~ /@.*@/ ) { (8) if (&User-Name =~ /@.*@/ ) -> FALSE (8) if (&User-Name =~ /\.\./ ) { (8) if (&User-Name =~ /\.\./ ) -> FALSE (8) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) { (8) if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/)) -> FALSE (8) if (&User-Name =~ /\.$/) { (8) if (&User-Name =~ /\.$/) -> FALSE (8) if (&User-Name =~ /@\./) { (8) if (&User-Name =~ /@\./) -> FALSE (8) } # policy filter_username = notfound (8) [preprocess] = ok (8) policy rewrite_called_station_id { (8) if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) { (8) if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) -> TRUE (8) if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) { (8) update request { (8) EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}} (8) --> 00-00-00-00-00-00 (8) &Called-Station-Id := 00-00-00-00-00-00 (8) } # update request = noop (8) if ("%{8}") { (8) EXPAND %{8} (8) --> (8) if ("%{8}") -> FALSE (8) [updated] = updated (8) } # if (&Called-Station-Id && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})([^0-9a-f](.+))?$/i)) = updated (8) ... skipping else for request 8: Preceding "if" was taken (8) } # policy rewrite_called_station_id = updated (8) policy rewrite_calling_station_id { (8) if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (8) if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE (8) if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (8) update request { (8) EXPAND %{toupper:%{1}-%{2}-%{3}-%{4}-%{5}-%{6}} (8) --> 00-00-00-00-00-00 (8) &Calling-Station-Id := 00-00-00-00-00-00 (8) } # update request = noop (8) [updated] = updated (8) } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated (8) ... skipping else for request 8: Preceding "if" was taken (8) } # policy rewrite_calling_station_id = updated (8) if (Cisco-AVPair[*] =~ /ssid=(.*)/i) { (8) if (Cisco-AVPair[*] =~ /ssid=(.*)/i) -> TRUE (8) if (Cisco-AVPair[*] =~ /ssid=(.*)/i) { (8) update request { (8) EXPAND %{1} (8) --> TestMain (8) Called-Station-SSID := TestMain (8) } # update request = noop (8) } # if (Cisco-AVPair[*] =~ /ssid=(.*)/i) = noop (8) [mschap] = noop (8) suffix: Checking for suffix after "@" (8) suffix: No '@' in User-Name = "pwd1", looking up realm NULL (8) suffix: No such realm "NULL" (8) [suffix] = noop (8) eap: Peer sent EAP Response (code 2) ID 9 length 43 (8) eap: Continuing tunnel setup (8) [eap] = ok (8) } # authorize = ok (8) Found Auth-Type = eap (8) # Executing group from file /tmp/we/radius/_root/etc/raddb/sites-enabled/default (8) authenticate { (8) eap: Expiring EAP session with state 0xc8c11f6dc9c80570 (8) eap: Finished EAP session with state 0x15a90c2012a01583 (8) eap: Previous EAP request found for state 0x15a90c2012a01583, 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: [eaptls verify] = ok (8) eap_peap: Done initial handshake (8) eap_peap: [eaptls process] = ok (8) eap_peap: Session established. Decoding tunneled attributes (8) eap_peap: PEAP state phase2 (8) eap_peap: EAP method MSCHAPv2 (26) (8) eap_peap: Got tunneled request (8) eap_peap: EAP-Message = 0x020900061a03 (8) eap_peap: Setting User-Name to pwd1 (8) eap_peap: Sending tunneled request to inner-tunnel (8) eap_peap: EAP-Message = 0x020900061a03 (8) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 (8) eap_peap: User-Name = "pwd1" (8) eap_peap: State = 0xc8c11f6dc9c805702f87e91a65b22ebd (8) eap_peap: Framed-MTU = 1400 (8) eap_peap: Called-Station-Id := "00-00-00-00-00-00" (8) eap_peap: Calling-Station-Id := "00-00-00-00-00-00" (8) eap_peap: Service-Type = Login-User (8) eap_peap: NAS-Port-Type = Wireless-802.11 (8) eap_peap: NAS-Port = 591 (8) eap_peap: NAS-Port-Id = "591" (8) eap_peap: NAS-IP-Address = 192.168.1.237 (8) eap_peap: Event-Timestamp = "Feb 22 2016 17:43:54 CET" (8) Virtual server inner-tunnel received request (8) EAP-Message = 0x020900061a03 (8) FreeRADIUS-Proxied-To = 127.0.0.1 (8) User-Name = "pwd1" (8) State = 0xc8c11f6dc9c805702f87e91a65b22ebd (8) Framed-MTU = 1400 (8) Called-Station-Id := "00-00-00-00-00-00" (8) Calling-Station-Id := "00-00-00-00-00-00" (8) Service-Type = Login-User (8) NAS-Port-Type = Wireless-802.11 (8) NAS-Port = 591 (8) NAS-Port-Id = "591" (8) NAS-IP-Address = 192.168.1.237 (8) Event-Timestamp = "Feb 22 2016 17:43:54 CET" (8) WARNING: Outer and inner identities are the same. User privacy is compromised. (8) server inner-tunnel { (8) session-state: No cached attributes (8) # Executing section authorize from file /tmp/we/radius/_root/etc/raddb/sites-enabled/inner-tunnel (8) authorize { (8) if (&outer.request:Called-Station-SSID) { (8) if (&outer.request:Called-Station-SSID) -> TRUE (8) if (&outer.request:Called-Station-SSID) { (8) update request { (8) &Called-Station-SSID := &outer.request:Called-Station-SSID -> 'TestMain' (8) } # update request = noop (8) } # if (&outer.request:Called-Station-SSID) = noop (8) [mschap] = noop (8) suffix: Checking for suffix after "@" (8) suffix: No '@' in User-Name = "pwd1", looking up realm NULL (8) suffix: No such realm "NULL" (8) [suffix] = noop (8) update control { (8) &Proxy-To-Realm := LOCAL (8) } # update control = noop (8) eap: Peer sent EAP Response (code 2) ID 9 length 6 (8) eap: No EAP Start, assuming it's an on-going EAP conversation (8) [eap] = updated (8) sql: EXPAND %{User-Name} (8) sql: --> pwd1 (8) sql: SQL-User-Name set to 'pwd1' rlm_sql (sql): Reserved connection (2) (8) sql: EXPAND SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id (8) sql: --> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'pwd1' ORDER BY id (8) sql: Executing select query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'pwd1' ORDER BY id (8) sql: User found in radcheck table (8) sql: Conditional check items matched, merging assignment check items (8) sql: Cleartext-Password := "test" (8) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id (8) sql: --> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'pwd1' ORDER BY id (8) sql: Executing select query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'pwd1' ORDER BY id (8) sql: EXPAND SELECT groupname FROM radusergroup WHERE (username = '%{SQL-User-Name}') or (username = 'ALL') ORDER BY priority (8) sql: --> SELECT groupname FROM radusergroup WHERE (username = 'pwd1') or (username = 'ALL') ORDER BY priority (8) sql: Executing select query: SELECT groupname FROM radusergroup WHERE (username = 'pwd1') or (username = 'ALL') ORDER BY priority (8) sql: User found in the group table (8) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{SQL-Group}' ORDER BY id (8) sql: --> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'wifi_main' ORDER BY id (8) sql: Executing select query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'wifi_main' ORDER BY id (8) sql: Group "wifi_main": Conditional check items matched (8) sql: Group "wifi_main": Merging assignment check items (8) sql: EXPAND SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{SQL-Group}' ORDER BY id (8) sql: --> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'wifi_main' ORDER BY id (8) sql: Executing select query: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'wifi_main' ORDER BY id (8) sql: Group "wifi_main": Merging reply items (8) sql: Cisco-AVPair += "ssid=TestMain" rlm_sql (sql): Released connection (2) (8) [sql] = ok (8) [expiration] = noop (8) [logintime] = noop (8) } # authorize = updated (8) Found Auth-Type = eap (8) # Executing group from file /tmp/we/radius/_root/etc/raddb/sites-enabled/inner-tunnel (8) authenticate { (8) eap: Expiring EAP session with state 0xc8c11f6dc9c80570 (8) eap: Finished EAP session with state 0xc8c11f6dc9c80570 (8) eap: Previous EAP request found for state 0xc8c11f6dc9c80570, released from the list (8) eap: Peer sent packet with method EAP MSCHAPv2 (26) (8) eap: Calling submodule eap_mschapv2 to process data (8) eap: Sending EAP Success (code 3) ID 9 length 4 (8) eap: Freeing handler (8) [eap] = ok (8) } # authenticate = ok (8) # Executing section post-auth from file /tmp/we/radius/_root/etc/raddb/sites-enabled/inner-tunnel (8) post-auth { (8) sql: EXPAND .query (8) sql: --> .query (8) sql: Using query template 'query' rlm_sql (sql): Reserved connection (3) (8) sql: EXPAND %{User-Name} (8) sql: --> pwd1 (8) sql: SQL-User-Name set to 'pwd1' (8) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') (8) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'pwd1', '', 'Access-Accept', '2016-02-22 17:43:54') (8) sql: Executing query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'pwd1', '', 'Access-Accept', '2016-02-22 17:43:54') (8) sql: SQL query returned: success (8) sql: 1 record(s) updated rlm_sql (sql): Released connection (3) (8) [sql] = ok (8) update { (8) &outer.session-state::Cisco-AVPair += &reply:Cisco-AVPair[*] -> 'ssid=TestMain' (8) &outer.session-state::MS-MPPE-Encryption-Policy += &reply:MS-MPPE-Encryption-Policy[*] -> Encryption-Allowed (8) &outer.session-state::MS-MPPE-Encryption-Types += &reply:MS-MPPE-Encryption-Types[*] -> RC4-40or128-bit-Allowed (8) &outer.session-state::MS-MPPE-Send-Key += &reply:MS-MPPE-Send-Key[*] -> 0xd9f718f6b60ec85b37371f878e76bef4 (8) &outer.session-state::MS-MPPE-Recv-Key += &reply:MS-MPPE-Recv-Key[*] -> 0x86ba2d467800ab435f8480cca124daef (8) &outer.session-state::EAP-Message += &reply:EAP-Message[*] -> 0x03090004 (8) &outer.session-state::Message-Authenticator += &reply:Message-Authenticator[*] -> 0x00000000000000000000000000000000 (8) &outer.session-state::User-Name += &reply:User-Name[*] -> 'pwd1' (8) } # update = noop (8) update outer.session-state { (8) MS-MPPE-Encryption-Policy !* ANY (8) MS-MPPE-Encryption-Types !* ANY (8) MS-MPPE-Send-Key !* ANY (8) MS-MPPE-Recv-Key !* ANY (8) Message-Authenticator !* ANY (8) EAP-Message !* ANY (8) Proxy-State !* ANY (8) } # update outer.session-state = noop (8) } # post-auth = ok (8) } # server inner-tunnel (8) Virtual server sending reply (8) Cisco-AVPair = "ssid=TestMain" (8) MS-MPPE-Encryption-Policy = Encryption-Allowed (8) MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed (8) MS-MPPE-Send-Key = 0xd9f718f6b60ec85b37371f878e76bef4 (8) MS-MPPE-Recv-Key = 0x86ba2d467800ab435f8480cca124daef (8) EAP-Message = 0x03090004 (8) Message-Authenticator = 0x00000000000000000000000000000000 (8) User-Name = "pwd1" (8) eap_peap: Got tunneled reply code 2 (8) eap_peap: Cisco-AVPair = "ssid=TestMain" (8) eap_peap: MS-MPPE-Encryption-Policy = Encryption-Allowed (8) eap_peap: MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed (8) eap_peap: MS-MPPE-Send-Key = 0xd9f718f6b60ec85b37371f878e76bef4 (8) eap_peap: MS-MPPE-Recv-Key = 0x86ba2d467800ab435f8480cca124daef (8) eap_peap: EAP-Message = 0x03090004 (8) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (8) eap_peap: User-Name = "pwd1" (8) eap_peap: Got tunneled reply RADIUS code 2 (8) eap_peap: Cisco-AVPair = "ssid=TestMain" (8) eap_peap: MS-MPPE-Encryption-Policy = Encryption-Allowed (8) eap_peap: MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed (8) eap_peap: MS-MPPE-Send-Key = 0xd9f718f6b60ec85b37371f878e76bef4 (8) eap_peap: MS-MPPE-Recv-Key = 0x86ba2d467800ab435f8480cca124daef (8) eap_peap: EAP-Message = 0x03090004 (8) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (8) eap_peap: User-Name = "pwd1" (8) eap_peap: Tunneled authentication was successful (8) eap_peap: SUCCESS (8) eap_peap: Saving tunneled attributes for later (8) eap: Sending EAP Request (code 1) ID 10 length 43 (8) eap: EAP session adding &reply:State = 0x15a90c201da31583 (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 /tmp/we/radius/_root/etc/raddb/sites-enabled/default (8) session-state: Saving cached attributes (8) Cisco-AVPair += "ssid=TestMain" (8) User-Name += "pwd1" (8) Sent Access-Challenge Id 50 from 192.168.1.1:1812 to 192.168.1.237:1645 length 0 (8) EAP-Message = 0x010a002b190017030100206926c93f1d3a251469fb2bcf248773ffda9bfd76fd5bc2b08efdb1d6dc714e2f (8) Message-Authenticator = 0x00000000000000000000000000000000 (8) State = 0x15a90c201da315839a62d961a44b0787 (8) Finished request