Hello, I'm using FreeRadius 2.1.12 (Debian stable) with PostgreSQL database to do AAA for wifi (PEAP inner-tunnel) clients via Mikrotik (RouterOS) APs. Everything works fine except that when accounting records are INSERTed in the radacct table, the callingstationid field is left blank instead of being populated with the MAC address of the calling station. This is rather strange, because the Calling-Station-Id is present in the Access-Request, and is the correct format (no wimax rubbish). -- DEBUG -- rad_recv: Access-Request packet from host 192.168.13.4 port 41720, id=192, length=219 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x0200000c01636c6561766572 Message-Authenticator = 0x434e50ee2a38b4327019b1f023d7006e NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 0 length 12 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [files] users: Matched entry DEFAULT at line 175 ++[files] returns ok [sql] expand: %{User-Name} -> cleaver [sql] sql_set_user escaped user --> 'cleaver' rlm_sql (sql): Reserving sql socket id: 4 [sql] expand: SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = 'cleaver' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 2 , fields = 5 [sql] User found in radcheck table [sql] expand: SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = 'cleaver' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 5 [sql] expand: SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority -> SELECT GroupName FROM radusergroup WHERE UserName='cleaver' ORDER BY priority rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 1 rlm_sql (sql): Released sql socket id: 4 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] EAP Identity [eap] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap] returns handled Sending Access-Challenge of id 192 to 192.168.13.4 port 41720 Session-Timeout := 1800 EAP-Message = 0x010100061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053eed241cd2358f2aa5aaaf3fc2 Finished request 0. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 59644, id=193, length=433 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053eed241cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020100d01980000000c616030100c1010000bd030153d2019cb70c22292cf72fa06046597aa60d5c8a8c593674b564308f7a8eafeb000054c014c00ac022c02100390038c00fc0050035c012c008c01cc01b00160013c00dc003000ac013c009c01fc01e00330032c00ec004002fc011c007c00cc002000500040015001200090014001100080006000300ff01000040000b000403000102000a00340032000e000d0019000b000c00180009000a00160017000800060007001400150004000500120013000100020003000f00100011 Message-Authenticator = 0xe7f541f1fe5aca909fd60af2ce86aa45 NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 1 length 208 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 198 [peap] Length Included [peap] eaptls_verify returned 11 [peap] (other): before/accept initialization [peap] TLS_accept: before/accept initialization [peap] <<< TLS 1.0 Handshake [length 00c1], ClientHello [peap] TLS_accept: SSLv3 read client hello A [peap] >>> TLS 1.0 Handshake [length 0039], ServerHello [peap] TLS_accept: SSLv3 write server hello A [peap] >>> TLS 1.0 Handshake [length 1455], Certificate [peap] TLS_accept: SSLv3 write certificate A [peap] >>> TLS 1.0 Handshake [length 014b], ServerKeyExchange [peap] TLS_accept: SSLv3 write key exchange A [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [peap] TLS_accept: SSLv3 write server done A [peap] TLS_accept: SSLv3 flush data [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 193 to 192.168.13.4 port 59644 EAP-Message = 0x0102040019c0000015f1160301003902000035030153d2019c19456f2f53451c3160934c0e061b78cd24d0e8237107a07ad789e70a00c01400000dff01000100000b00040300010216030114550b00145100144e0006403082063c30820524a00302010202030eadac300d06092a864886f70d01010b050030818c310b300906035504061302494c31163014060355040a130d5374617274436f6d204c74642e312b3029060355040b1322536563757265204469676974616c204365727469666963617465205369676e696e67313830360603550403132f5374617274436f6d20436c6173732031205072696d61727920496e7465726d656469617465 EAP-Message = 0x20536572766572204341301e170d3134303232303138353131315a170d3135303232313133343733375a304e310b3009060355040613024247311a3018060355040313117261646975732e646174616d61782e62673123302106092a864886f70d01090116147765626d617374657240646174616d61782e626730820122300d06092a864886f70d01010105000382010f003082010a0282010100c0292ddae54021f9fe735191ff7292fb3eac929d3f958bb8c98aad1e040fbcbac519c7cfb9b64e8344fe7c7fba3c9447c9e6b1d9bdd86776a2343ab1ab141316f030740232147e896627594abab0e45cf4de79a82269e985aa374ba9e482ac351282 EAP-Message = 0x6618d71751108021ba0bc607cbb0c7616bd46c5e266db36faa8ccb063b2329866295968f9d7bd5ff6b83617b9780ef9a2c8668f52a90f9ed73d5308efc93360e6de3e21296b51c40164fc00c9fc4d61f18e759db66b1708362b51cbcbb2ee926a0a59118064cb9c4e8fad26541cb4da5480e654cb4c37a4b3354a22ffffc7f0655929fd1e9d4749950ab2f5a51f054e0851f814523d792b5e6e9fc7958eb0203010001a38202e2308202de30090603551d1304023000300b0603551d0f0404030203a830130603551d25040c300a06082b06010505070301301d0603551d0e04160414ddbc53b20d58f98e6db7e795176aab2ed8f5275d301f0603551d EAP-Message = 0x23041830168014eb4234d098b0ab9ff41b6b08f7cc642eef0e2c4530280603551d110421301f82117261646975732e646174616d61782e6267820a646174616d61782e6267308201560603551d200482014d308201493008060667810c0102013082013b060b2b0601040181b5370102033082012a302e06082b060105050702011622687474703a2f2f7777772e737461727473736c2e636f6d2f706f6c6963792e7064663081f706082b060105050702023081ea302716205374617274436f6d2043657274696669636174696f6e20417574686f7269747930030201011a81be54686973206365727469666963617465207761732069737375656420 EAP-Message = 0x6163636f7264696e6720746f Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053eec271cd2358f2aa5aaaf3fc2 Finished request 1. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 55690, id=194, length=231 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053eec271cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020200061900 Message-Authenticator = 0xa8463c35eeecca48b017bdafe961171e NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 2 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 194 to 192.168.13.4 port 55690 EAP-Message = 0x010303fc19402074686520436c61737320312056616c69646174696f6e20726571756972656d656e7473206f6620746865205374617274436f6d20434120706f6c6963792c2072656c69616e6365206f6e6c7920666f722074686520696e74656e64656420707572706f736520696e20636f6d706c69616e6365206f66207468652072656c79696e67207061727479206f626c69676174696f6e732e30350603551d1f042e302c302aa028a0268624687474703a2f2f63726c2e737461727473736c2e636f6d2f637274312d63726c2e63726c30818e06082b06010505070101048181307f303906082b06010505073001862d687474703a2f2f6f6373 EAP-Message = 0x702e737461727473736c2e636f6d2f7375622f636c617373312f7365727665722f6361304206082b060105050730028636687474703a2f2f6169612e737461727473736c2e636f6d2f63657274732f7375622e636c617373312e7365727665722e63612e63727430230603551d12041c301a8618687474703a2f2f7777772e737461727473736c2e636f6d2f300d06092a864886f70d01010b050003820101005e7443be92a6e0ddc6b48e58d9a0e40059c6328814d556263095548d82d0ebe0f91d34feb0bb1aeaa5d8964fd244c2e6726b66e3a690e8e8156561cc3d75fd9126e726a4a6b00d0b9b0601ba144d2700ae0acd415c9050f7b74aaba7a9 EAP-Message = 0x2e72de4c98719c4845bf68eb2bdaacbb3a1e030f2d429cfa40cdc11fc338a3628beedd09fc2acb6cd6c73ddca416e6ce4d45fbc41d8ebfefb01b54e453e8e34efd6ee615636de6b286639cc44642d7253839632fff191c628d88943bbc3dc1aa3c54704e6fce6aee5958625c597c8ccfd024d96c313283c28eddc52f7fc5c0861cd4a0cd05bbdfc21a031851738200a5a96e8cadfebefa5f8d7a18c91d65b750e5a67f000638308206343082041ca003020102020118300d06092a864886f70d0101050500307d310b300906035504061302494c31163014060355040a130d5374617274436f6d204c74642e312b3029060355040b1322536563757265 EAP-Message = 0x204469676974616c204365727469666963617465205369676e696e6731293027060355040313205374617274436f6d2043657274696669636174696f6e20417574686f72697479301e170d3037313032343230353431375a170d3137313032343230353431375a30818c310b300906035504061302494c31163014060355040a130d5374617274436f6d204c74642e312b3029060355040b1322536563757265204469676974616c204365727469666963617465205369676e696e67313830360603550403132f5374617274436f6d20436c6173732031205072696d61727920496e7465726d6564696174652053657276657220434130820122300d06 EAP-Message = 0x092a864886f70d01 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053eef261cd2358f2aa5aaaf3fc2 Finished request 2. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 44014, id=195, length=231 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053eef261cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020300061900 Message-Authenticator = 0x55a162fc3d5e927e809dfa9f7a29e5dd NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 3 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 195 to 192.168.13.4 port 44014 EAP-Message = 0x010403fc1940010105000382010f003082010a0282010100b689c6acef09527807ac9263d0f44418188480561f91aee187fa3250b4d34706f0e6075f700e10f71dc0ce103634855a0f92ac83c6ac58523fba38e8fce7a724e240a60876c0926e9e2a6d4d3f6e61200adb59ded27d63b33e46fefa215118d7cd30a6ed076e3b7087b4f9faebee823c056f92f7a4dc0a301e9373fe07cad75f809d225852ae06da8b872369b0e42ad8ea83d2bdf371db705a280faf5a387045123f304dcd3baf17e50fcba0a95d48aab16150cb34cd3c5cc30be810c08c9bf0030362feb26c3e720eee1c432ac9480e5739c43121c810c12c87fe5495521f523c31129b7f EAP-Message = 0xe7c0a0a559d5e28f3ef0d5a8e1d77031a9c4b3cfaf6d532f06f4a70203010001a38201ad308201a9300f0603551d130101ff040530030101ff300e0603551d0f0101ff040403020106301d0603551d0e04160414eb4234d098b0ab9ff41b6b08f7cc642eef0e2c45301f0603551d230418301680144e0bef1aa4405ba517698730ca346843d041aef2306606082b06010505070101045a3058302706082b06010505073001861b687474703a2f2f6f6373702e737461727473736c2e636f6d2f6361302d06082b060105050730028621687474703a2f2f7777772e737461727473736c2e636f6d2f73667363612e637274305b0603551d1f0454305230 EAP-Message = 0x27a025a0238621687474703a2f2f7777772e737461727473736c2e636f6d2f73667363612e63726c3027a025a0238621687474703a2f2f63726c2e737461727473736c2e636f6d2f73667363612e63726c3081800603551d20047930773075060b2b0601040181b5370102013066302e06082b060105050702011622687474703a2f2f7777772e737461727473736c2e636f6d2f706f6c6963792e706466303406082b060105050702011628687474703a2f2f7777772e737461727473736c2e636f6d2f696e7465726d6564696174652e706466300d06092a864886f70d010105050003820201002109493ea5886ee00b8b48da314d8ff75657a2e1d3 EAP-Message = 0x6257e9b556f38545753be5501f048be6a05a3ee700ae85d0fbff200364cbad02e1c69172f8a34dd6dee8cc3fa18aa2e37c37a7c64f8f35d6f4d66e067bdd21d9cf56ffcb302249fe8904f385e5aaf1e71fe875904dddf946f74234f745580c110d84b0c6da5d3ef9019ee7e1da5595be741c7bfc4d144fac7e55477d7bf4a50d491e95e8f712c1ccff76a62547d0f37535be97b75816ebaa5c786fec5330afea044dcca902e3f0b60412f630b1113d904e5664d7dc3c435f7339ef4baf87ebf6fe68884472ead207c669b0c1a18bef1749d761b145485f3b2021e95bb2ccf4d7e931f50b15613b7a94e3ebd9bc7f94ae6ae3626296a8647cb887f39932 EAP-Message = 0x7e92a252bebbf865 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053eee211cd2358f2aa5aaaf3fc2 Finished request 3. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 33341, id=196, length=231 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053eee211cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020400061900 Message-Authenticator = 0x3842e104ca596ede64f0b0be858ecbeb NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 4 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 196 to 192.168.13.4 port 33341 EAP-Message = 0x010503fc1940cfc9f230fc8bc1c2a696d75f89e15c3480f58f47072fb491bfb1a27e5f4b5ad05b9f248605515a690365434971c5e06f94346bf61bd8a9b04c7e53eb8f48dfca33b548fa364a1a53a6330cd089cd4915cd89313c90c072d7654b52358a461144b93d8e2865a63e799e5c084429adb035112e214eb8d2e7103e5d8483b3c3c2e4d2c6fd094b7409ddf1b3d3193e800da20b19f038e7c5c2afe223db61e29d5c6e2089492e236ab262c145b49faf8ba7f1223bf87de290d07a19fb4a4ce3d27d5f4a8303ed27d6239e6b8db459a2d9ef6c8229dd75193c3f4c108defbb7527d2ae83a7a8ce5ba70007cd308207c9308205b1a00302010202 EAP-Message = 0x0101300d06092a864886f70d0101050500307d310b300906035504061302494c31163014060355040a130d5374617274436f6d204c74642e312b3029060355040b1322536563757265204469676974616c204365727469666963617465205369676e696e6731293027060355040313205374617274436f6d2043657274696669636174696f6e20417574686f72697479301e170d3036303931373139343633365a170d3336303931373139343633365a307d310b300906035504061302494c31163014060355040a130d5374617274436f6d204c74642e312b3029060355040b1322536563757265204469676974616c20436572746966696361746520 EAP-Message = 0x5369676e696e6731293027060355040313205374617274436f6d2043657274696669636174696f6e20417574686f7269747930820222300d06092a864886f70d01010105000382020f003082020a0282020100c188db09bc6c467c789f957bb53390f27262d6c1362022245ecee977f2430aa20664a4cc8e36f838e623f06e6db13cdd72a3851ca1d33db4332bd32faffeeab0415967b6c4067d0a9e7485d6794c80377adf39055259f7f41b4643a4d28585d2c371f3756234ba2c8a7f1e8feeed34d011c796cd523dba33d6dd4dde0b3b4a4b9fc2262ffab5161c723577ca3c5de6cae1268b1a36765c01db741425feedb5a0880fdd78ca2d1f079730 EAP-Message = 0x012d7279fa46d6132aa8b9a6ab83491de5f2efdde4018e180a8f6353168562a90e193accb566a6c26b7407e42be1763eb46dd8f644e173621f3bc4bea05356256c5109f7aaabcabf76fd6d9bf39ddbbf3d66bc0c56aaaf9848953a4bdfa75850d93875a95bea430c02ff99ebe86c4d705b29659cddaa5dccaf0131ec0cebd28de8ea9c7be66ef727660c1a48d76e42e33fde213e7be10d70fb63aaa86c1a54b45c257ac9a2c98b16a6bb2c7e175e054d586e121d01ee12100dc6327f18fffcf4facd6e91e83649be1a48698bc2964d1a12b26917c10a90d6fa792248bfba7b69f870c7fa7a37d8d80dd2764f57ff90b7e391d2ddefc260b7673addfeaa EAP-Message = 0x9cf0d48b7f7222ce Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053ee9201cd2358f2aa5aaaf3fc2 Finished request 4. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 40019, id=197, length=231 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053ee9201cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020500061900 Message-Authenticator = 0x1c4af62fc26823cf08d71d58cd5e3b37 NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 5 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 197 to 192.168.13.4 port 40019 EAP-Message = 0x010603fc1940c69f97b6f8af8aa010a8d9fb18c6b6b55c523c89b6192a73010a0f03b31260f27a2f81dba36eff263097f58bdd8957b6ad3db3af2bc5b77602f0a5d62b9a86142a72f6e3338c5d094b13dfbb8c7413524b0203010001a38202523082024e300c0603551d13040530030101ff300b0603551d0f0404030201ae301d0603551d0e041604144e0bef1aa4405ba517698730ca346843d041aef230640603551d1f045d305b302ca02aa0288626687474703a2f2f636572742e7374617274636f6d2e6f72672f73667363612d63726c2e63726c302ba029a0278625687474703a2f2f63726c2e7374617274636f6d2e6f72672f73667363612d EAP-Message = 0x63726c2e63726c3082015d0603551d2004820154308201503082014c060b2b0601040181b5370101013082013b302f06082b060105050702011623687474703a2f2f636572742e7374617274636f6d2e6f72672f706f6c6963792e706466303506082b060105050702011629687474703a2f2f636572742e7374617274636f6d2e6f72672f696e7465726d6564696174652e7064663081d006082b060105050702023081c330271620537461727420436f6d6d65726369616c20285374617274436f6d29204c74642e30030201011a81974c696d69746564204c696162696c6974792c2072656164207468652073656374696f6e202a4c6567616c204c EAP-Message = 0x696d69746174696f6e732a206f6620746865205374617274436f6d2043657274696669636174696f6e20417574686f7269747920506f6c69637920617661696c61626c6520617420687474703a2f2f636572742e7374617274636f6d2e6f72672f706f6c6963792e706466301106096086480186f8420101040403020007303806096086480186f842010d042b16295374617274436f6d20467265652053534c2043657274696669636174696f6e20417574686f72697479300d06092a864886f70d01010505000382020100166c99f4660c34f5d0855e7d0aecda104e381c5edfa625054b9132c1e83bf13ddd44095b07498a29cb6602b7b19af72598 EAP-Message = 0x093c8e1be1dd36872b4bbb68d339663da026c7f239911d51ab827b7ed5ce5ae4e2035770699708f95e58a60adf8c069a451616380a5e57f662c77a0205e6bc1eb5f29ef4a92983f8b214e36e288744c3901ade38a93cac434d6445cedd28a95cf2737b04f817e8abb1f32e5c646e73313a12b8bcb311e47d8f81519a3b8d89f44d93667b3c03edd39a1d9af36550f5a0d0759f2faff0ea824398f8699c8979c4438e4672e3643612aff7251e388990777ec36b6ab9c3cb444bac78908be7c72c1e4b1144c8345227cd0a5d9f85c189d51a78f295105332dd80846675d9b56828fb612ebe84a838c0991286a51e6764ad062e2fa97085c7960f7c8965f5 EAP-Message = 0x8e43540eabdda580 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053ee8231cd2358f2aa5aaaf3fc2 Finished request 5. Going to the next request Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 41337, id=198, length=231 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053ee8231cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020600061900 Message-Authenticator = 0xe253ac1dbf0e01f0521a1e3b4c1374c6 NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 6 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 198 to 192.168.13.4 port 41337 EAP-Message = 0x010702291900399460c034c996702ca312f51f487bbd1c7e6bb79d90f4223baef8fc2acafa8252a0efaf4b5593ebc1b5f0228bac344e262204a1872c754ab7e57d13d7b80c64c036d2c92f86128c2309c11b823b7349a36a578794e5d678c5994363e34de0772de165997269041a4709e60f015624fb1fbf0e79a9582eb9c409017e95ba6d00063eb2ea4a1039d8d02bf5bfec75bf9702c5091b08dc5537e281fb3784436220cae7564b65eafe6cc1249324a134eb05ff9a22ae9b7d3ff165510aa6306ab3f4881c800dfc728ae8835e160301014b0c00014703001741047e3580856cd5edf4f4abefd63bc85b6423cda233a8c0e45c47488bbcaeb217 EAP-Message = 0x2762be19884aa51fca0b9def15c868fb9c545b3700c30cc336d2abcfde87c2dece01003b878453bd62f496364a78ae88dcc832848ec534d060e2343af9f1f5f688b2c0cea2f2655534e52313738765fa800db99a33d1a7e5f58a54370f08bf9cb77a29a6ff09ceb6ba694b8ab033c3ee7bb307d4fe058d8cc19fb9287c950782d6d9450b1e93e3a8f1e1f64c8b5ed98e86524362d0ab4ca3551bd32d606eee37e1d33a73916fbf3a87f1f2fa21175e351f8227a2253dbddbac3ac6d55b5a279ddef8d82f8e11e7e6975f71fed931032f566e47e2d62d3b2e1a83a8c0ec2ada6559f4f659b372c6a8e3ff80f072ea5a4af4fa612bd20857dbb419130348 EAP-Message = 0x063cd372cf67ce5d60124666927a47f1eabd6e2d4ddd73740223398bb4e53ffc949610d302d516030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053eeb221cd2358f2aa5aaaf3fc2 Finished request 6. Going to the next request Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 52983, id=199, length=369 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053eeb221cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020700901980000000861603010046100000424104058b9c5c1242b8575b45d5e832a09f6407a3b4b53375341b836b71ae6c439188dacd300428bfe2b83d3ae800551117332848d6a2bf086a011017ba361695109614030100010116030100306187693e81ba7869921c7b270631a94f20814177db82f30fc1546cf26b8d2f96140309976b5a0c5f023bcbc131e10994 Message-Authenticator = 0x83f38d62342a7f24718fbcab145767dc NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 7 length 144 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 134 [peap] Length Included [peap] eaptls_verify returned 11 [peap] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange [peap] TLS_accept: SSLv3 read client key exchange A [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] [peap] <<< TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 read finished A [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] [peap] TLS_accept: SSLv3 write change cipher spec A [peap] >>> TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 write finished A [peap] TLS_accept: SSLv3 flush data [peap] (other): SSL negotiation finished successfully SSL Connection Established [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 199 to 192.168.13.4 port 52983 EAP-Message = 0x01080041190014030100010116030100308cc8c199f323cc041f68e63f8a2f12b585c01804d096eee279062366279d8feee13fd3dfdb508487fbd475dbed8236dc Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053eea2d1cd2358f2aa5aaaf3fc2 Finished request 7. Going to the next request Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 60602, id=200, length=231 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053eea2d1cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020800061900 Message-Authenticator = 0x475e745cc00cf27b19b89a29ca12c17b NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 8 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake is finished [peap] eaptls_verify returned 3 [peap] eaptls_process returned 3 [peap] EAPTLS_SUCCESS [peap] Session established. Decoding tunneled attributes. [peap] Peap state TUNNEL ESTABLISHED ++[eap] returns handled Sending Access-Challenge of id 200 to 192.168.13.4 port 60602 EAP-Message = 0x0109002b19001703010020374e020851e52025f5d84f795b804a0a630e889fb780a25f3d880e1dde84c467 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053ee52c1cd2358f2aa5aaaf3fc2 Finished request 8. Going to the next request Waking up in 4.8 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 54334, id=201, length=305 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053ee52c1cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x0209005019001703010020544f2f672ecbb7e80643c59adcf0eae044e137cbc08440550e933464a65dacf517030100204a4b03253c233a652a1f6319ab1f1efe70dfd3004b9b3167212592ee5e5a5111 Message-Authenticator = 0x4eeadf3eeacefc6d290fe9e6949a9434 NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 9 length 80 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state WAITING FOR INNER IDENTITY [peap] Identity - cleaver [peap] Got inner identity 'cleaver' [peap] Setting default EAP type for tunneled EAP session. [peap] Got tunneled request EAP-Message = 0x0209000c01636c6561766572 server { [peap] Setting User-Name to cleaver Sending tunneled request EAP-Message = 0x0209000c01636c6561766572 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "cleaver" Service-Type = Framed-User Framed-MTU = 1400 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 server inner-tunnel { # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authorize {...} [eap] EAP packet type response id 9 length 12 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [files] users: Matched entry DEFAULT at line 175 ++[files] returns ok [sql] expand: %{User-Name} -> cleaver [sql] sql_set_user escaped user --> 'cleaver' rlm_sql (sql): Reserving sql socket id: 3 [sql] expand: SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = 'cleaver' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 2 , fields = 5 [sql] User found in radcheck table [sql] expand: SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = 'cleaver' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 5 [sql] expand: SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority -> SELECT GroupName FROM radusergroup WHERE UserName='cleaver' ORDER BY priority rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 1 rlm_sql (sql): Released sql socket id: 3 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authenticate {...} [eap] EAP Identity [eap] processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge ++[eap] returns handled } # server inner-tunnel [peap] Got tunneled reply code 11 Session-Timeout := 1800 EAP-Message = 0x010a00211a010a001c106f35422b2de0227f2c2b8d732d233bf0636c6561766572 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x4c05f3034c0fe9a96e66b7b13f9be167 [peap] Got tunneled reply RADIUS code 11 Session-Timeout := 1800 EAP-Message = 0x010a00211a010a001c106f35422b2de0227f2c2b8d732d233bf0636c6561766572 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x4c05f3034c0fe9a96e66b7b13f9be167 [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 201 to 192.168.13.4 port 54334 EAP-Message = 0x010a004b19001703010040dc69c9263fc56ccb7d790c344b9076897269cf3715611e19ac8d357005f9bfa3cf33e84873ed6d12b96614786b43c80aab41e1a64f43db1bc9076c6d597ca674 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053ee42f1cd2358f2aa5aaaf3fc2 Finished request 9. Going to the next request Waking up in 4.7 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 46152, id=202, length=369 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053ee42f1cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020a0090190017030100202617cdd5e2cad6ab75d32a3c9c05c2d6d47e25af08b8d5abed9d06dd2a9649271703010060722908436bf9adae2c84e374bda4f228074e64be92d97421d081fd02c6c219bac6c1372d4579b41b5c85e1b68e9d51b2aa5dbdce53c8ec7af5aeccffa7aa9efeea3e094ff87d46dc35e63f1748b9fc495d89a59cc80b8984a004bc91ab59dcc0 Message-Authenticator = 0x24d078ce9aecea7e3ba0be5332d544c2 NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 10 length 144 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state phase2 [peap] EAP type mschapv2 [peap] Got tunneled request EAP-Message = 0x020a00421a020a003d31610c5fb65f12ca5f9b3e38a96d0a16220000000000000000529d636d7c546dd5de8e76b5751ee13015ea1bfdcfa0ca5800636c6561766572 server { [peap] Setting User-Name to cleaver Sending tunneled request EAP-Message = 0x020a00421a020a003d31610c5fb65f12ca5f9b3e38a96d0a16220000000000000000529d636d7c546dd5de8e76b5751ee13015ea1bfdcfa0ca5800636c6561766572 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "cleaver" State = 0x4c05f3034c0fe9a96e66b7b13f9be167 Service-Type = Framed-User Framed-MTU = 1400 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 server inner-tunnel { # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authorize {...} [eap] EAP packet type response id 10 length 66 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [files] users: Matched entry DEFAULT at line 175 ++[files] returns ok [sql] expand: %{User-Name} -> cleaver [sql] sql_set_user escaped user --> 'cleaver' rlm_sql (sql): Reserving sql socket id: 2 [sql] expand: SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = 'cleaver' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 2 , fields = 5 [sql] User found in radcheck table [sql] expand: SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = 'cleaver' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 5 [sql] expand: SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority -> SELECT GroupName FROM radusergroup WHERE UserName='cleaver' ORDER BY priority rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 1 rlm_sql (sql): Released sql socket id: 2 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [mschapv2] # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel [mschapv2] +- entering group MS-CHAP {...} [mschap] Creating challenge hash with username: cleaver [mschap] Told to do MS-CHAPv2 for cleaver with NT-Password [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success ++[eap] returns handled } # server inner-tunnel [peap] Got tunneled reply code 11 Session-Timeout := 1800 EAP-Message = 0x010b00331a030a002e533d36443735454438363231314442423730393235354437383530383330323446443046324236324139 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x4c05f3034d0ee9a96e66b7b13f9be167 [peap] Got tunneled reply RADIUS code 11 Session-Timeout := 1800 EAP-Message = 0x010b00331a030a002e533d36443735454438363231314442423730393235354437383530383330323446443046324236324139 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x4c05f3034d0ee9a96e66b7b13f9be167 [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 202 to 192.168.13.4 port 46152 EAP-Message = 0x010b005b19001703010050cbb8af5543fab16b513a6374c93cc275f0680f64d183e2ec1bb7c71d3393b9c1331f0e67f02ee0b799d80940dc6a3d6f39c3bc96162323292ff0357a009f3acb32dbbb79735543a2f6897c0a2cd6c948 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053ee72e1cd2358f2aa5aaaf3fc2 Finished request 10. Going to the next request Waking up in 4.7 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 55110, id=203, length=305 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053ee72e1cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020b005019001703010020466fc6985c0987334d5c1acb554064d654956705af40cfc23f3587ecb3eb86941703010020de6fc4407f156d1dc4e9454d3d1da0627b69bb4748693f5caffb2a8caea79433 Message-Authenticator = 0x6aecd12ca46c2ed0f2136abb95e278e1 NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 11 length 80 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state phase2 [peap] EAP type mschapv2 [peap] Got tunneled request EAP-Message = 0x020b00061a03 server { [peap] Setting User-Name to cleaver Sending tunneled request EAP-Message = 0x020b00061a03 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "cleaver" State = 0x4c05f3034d0ee9a96e66b7b13f9be167 Service-Type = Framed-User Framed-MTU = 1400 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 server inner-tunnel { # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authorize {...} [eap] EAP packet type response id 11 length 6 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [files] users: Matched entry DEFAULT at line 175 ++[files] returns ok [sql] expand: %{User-Name} -> cleaver [sql] sql_set_user escaped user --> 'cleaver' rlm_sql (sql): Reserving sql socket id: 1 [sql] expand: SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, Attribute, Value, Op FROM radcheck WHERE Username = 'cleaver' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 2 , fields = 5 [sql] User found in radcheck table [sql] expand: SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, UserName, Attribute, Value, Op FROM radreply WHERE Username = 'cleaver' ORDER BY id rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 5 [sql] expand: SELECT GroupName FROM radusergroup WHERE UserName='%{SQL-User-Name}' ORDER BY priority -> SELECT GroupName FROM radusergroup WHERE UserName='cleaver' ORDER BY priority rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 0 , fields = 1 rlm_sql (sql): Released sql socket id: 1 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [eap] Freeing handler ++[eap] returns ok # Executing section session from file /etc/freeradius/sites-enabled/inner-tunnel +- entering group session {...} [sql] expand: %{User-Name} -> cleaver [sql] sql_set_user escaped user --> 'cleaver' [sql] expand: SELECT COUNT(*) FROM radacct WHERE UserName='%{SQL-User-Name}' AND AcctStopTime IS NULL -> SELECT COUNT(*) FROM radacct WHERE UserName='cleaver' AND AcctStopTime IS NULL rlm_sql (sql): Reserving sql socket id: 0 rlm_sql_postgresql: Status: PGRES_TUPLES_OK rlm_sql_postgresql: query affected rows = 1 , fields = 1 rlm_sql (sql): Released sql socket id: 0 ++[sql] returns ok Login OK: [cleaver] (from client mikrotik03 port 0 cli CC-FA-00-C6-4A-A6 via TLS tunnel) WARNING: Empty post-auth section. Using default return values. # Executing section post-auth from file /etc/freeradius/sites-enabled/inner-tunnel } # server inner-tunnel [peap] Got tunneled reply code 2 Session-Timeout := 1800 MS-MPPE-Encryption-Policy = 0x00000001 MS-MPPE-Encryption-Types = 0x00000006 MS-MPPE-Send-Key = 0xe21015a00b64a87e6e02fc7698500f91 MS-MPPE-Recv-Key = 0xe1a2a8b724972b4ba2b9f8e7f3790e3b EAP-Message = 0x030b0004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "cleaver" [peap] Got tunneled reply RADIUS code 2 Session-Timeout := 1800 MS-MPPE-Encryption-Policy = 0x00000001 MS-MPPE-Encryption-Types = 0x00000006 MS-MPPE-Send-Key = 0xe21015a00b64a87e6e02fc7698500f91 MS-MPPE-Recv-Key = 0xe1a2a8b724972b4ba2b9f8e7f3790e3b EAP-Message = 0x030b0004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "cleaver" [peap] Tunneled authentication was successful. [peap] SUCCESS [peap] Saving tunneled attributes for later ++[eap] returns handled Sending Access-Challenge of id 203 to 192.168.13.4 port 55110 EAP-Message = 0x010c002b190017030100204851eb10a5682951f8da0bb7072b7681914648dc4746b0eff3b6139ed68f542e Message-Authenticator = 0x00000000000000000000000000000000 State = 0xed25053ee6291cd2358f2aa5aaaf3fc2 Finished request 11. Going to the next request Waking up in 4.7 seconds. rad_recv: Access-Request packet from host 192.168.13.4 port 57335, id=204, length=305 Service-Type = Framed-User Framed-MTU = 1400 User-Name = "cleaver" State = 0xed25053ee6291cd2358f2aa5aaaf3fc2 NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Calling-Station-Id = "CC-FA-00-C6-4A-A6" Called-Station-Id = "D4-CA-6D-F6-55-C1:datamax" EAP-Message = 0x020c005019001703010020bc9a7815ca619d39bb6d1a7f30cfa319318f6da9a6996c50ecb209f5370b8e8717030100201fe12a0976816a84d7eff293d9ddd18b4a74843b7044fe0c52fe2dd5a74dc98e Message-Authenticator = 0x7841be02d6f1e4c97d52e2e9ce37412f NAS-Identifier = "MikroTik" NAS-IP-Address = 192.168.13.4 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [eap] EAP packet type response id 12 length 80 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Peap state send tlv success [peap] Received EAP-TLV response. [peap] Success [peap] Using saved attributes from the original Access-Accept Session-Timeout := 1800 User-Name = "cleaver" [eap] Freeing handler ++[eap] returns ok Login OK: [cleaver] (from client mikrotik03 port 0 cli CC-FA-00-C6-4A-A6) WARNING: Empty post-auth section. Using default return values. # Executing section post-auth from file /etc/freeradius/sites-enabled/default Sending Access-Accept of id 204 to 192.168.13.4 port 57335 Session-Timeout := 1800 User-Name = "cleaver" MS-MPPE-Recv-Key = 0x752ff9b12af057a8ec7c4ec3ced5ab073e0f17efc28a92402da2e08eeb2f1751 MS-MPPE-Send-Key = 0x20f0a96db29944a3869a77df7fd6f6eeb84d2a7a62dbcd31fa441e93dcbc237d EAP-Message = 0x030c0004 Message-Authenticator = 0x00000000000000000000000000000000 Finished request 12. Going to the next request Waking up in 4.7 seconds. rad_recv: Accounting-Request packet from host 192.168.13.4 port 51157, id=205, length=153 Service-Type = Framed-User NAS-Port-Id = "wlan1" NAS-Port-Type = Wireless-802.11 User-Name = "cleaver" Acct-Session-Id = "82000027" Acct-Multi-Session-Id = "D4-CA-6D-F6-55-C1-CC-FA-00-C6-4A-A6-82-00-00-00-00-00-00-1F" Acct-Authentic = RADIUS Acct-Status-Type = Start NAS-Identifier = "MikroTik" Acct-Delay-Time = 0 NAS-IP-Address = 192.168.13.4 # Executing section preacct from file /etc/freeradius/sites-enabled/default +- entering group preacct {...} ++[preprocess] returns ok [acct_unique] Hashing 'NAS-Port-Id = "wlan1",Client-IP-Address = 192.168.13.4,NAS-IP-Address = 192.168.13.4,Acct-Session-Id = "82000027",User-Name = "cleaver"' [acct_unique] Acct-Unique-Session-ID = "e27c8233063681bb". ++[acct_unique] returns ok ++[files] returns noop # Executing section accounting from file /etc/freeradius/sites-enabled/default +- entering group accounting {...} [detail] expand: %{Packet-Src-IP-Address} -> 192.168.13.4 [detail] expand: /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d -> /var/log/freeradius/radacct/192.168.13.4/detail-20140725 [detail] /var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.13.4/detail-20140725 [detail] expand: %t -> Fri Jul 25 10:05:00 2014 ++[detail] returns ok [sql] expand: %{User-Name} -> cleaver [sql] sql_set_user escaped user --> 'cleaver' [sql] expand: %{NAS-Port} -> [sql] ... expanding second conditional [sql] expand: %{Acct-Delay-Time} -> 0 [sql] expand: INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctAuthentic, ConnectInfo_start, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, XAscendSessionSvrKey) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', NULLIF('%{Realm}', ''), '%{NAS-IP-Address}', %{%{NAS-Port}:-NULL}, '%{NAS-Port-Type}', ('%S'::timestamp - '%{%{Acct-Delay-Time}:-0}'::interval), '%{Acct-Authentic}', '%{Connect-Info}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet, 0, '%{X-Ascend-Session-Svr-Key}') -> INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctAuthentic, ConnectInfo_start, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, rlm_sql (sql): Reserving sql socket id: 4 rlm_sql_postgresql: Status: PGRES_COMMAND_OK rlm_sql_postgresql: query affected rows = 1 rlm_sql (sql): Released sql socket id: 4 ++[sql] returns ok [attr_filter.accounting_response] expand: %{User-Name} -> cleaver attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 205 to 192.168.13.4 port 51157 Finished request 13. Cleaning up request 13 ID 205 with timestamp +10 Going to the next request Waking up in 4.6 seconds. -- DEBUG -- I need the Calling-Station-Id in radacct for stale records cleaning and it's important for me that this value is inserted correctly. As you can see, the Calling-Station-Id = "CC-FA-00-C6-4A-A6" is passed to the RADIUS server in Access-Request and INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctAuthentic, ConnectInfo_start, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, XAscendSessionSvrKey) VALUES('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', NULLIF('%{Realm}', ''), '%{NAS-IP-Address}', %{%{NAS-Port}:-NULL}, '%{NAS-Port-Type}', ('%S'::timestamp - '%{%{Acct-Delay-Time}:-0}'::interval), '%{Acct-Authentic}', '%{Connect-Info}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', NULLIF('%{Framed-IP-Address}', '')::inet, 0, '%{X-Ascend-Session-Svr-Key}') -> INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctAuthentic, ConnectInfo_start, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, seems correct except that it seems truncated. I guess my problem is due to a configuration mistake, but I have not been able to locate it so far. Any suggestions? Thanks, Stoycho