Correlating Access-Requests and Replys
Arran Cudbard-Bell
a.cudbardb at freeradius.org
Fri Apr 22 19:55:26 CEST 2016
> On Apr 22, 2016, at 1:41 AM, Christian Strauf <strauf at rz.tu-clausthal.de> wrote:
>
>> Internally we track the progression of requests/responses.
>>
>> Working on something now to expose the ID of the state struct we use to do that.
>>
>> It'll only be in the v3.1.x branch though.
> That's brilliant. This makes things a lot easier. Thank you very much for looking into this, it's highly appreciated.
3, 2, 1 bikeshed...
Relevant lines are 746-751 src/main/log.c
The second number is the request that started the current authentication attempt. Makes it easier to find the initial request.
I really like the v3.1.x debug output, I think it's the cleanest we've ever gotten it.
-Arran
(1) Received Access-Request Id 0 from 127.0.0.1:52963 to 127.0.0.1:1812 via lo0 length 126
(1) User-Name = "anonymous"
(1) NAS-IP-Address = 127.0.0.1
(1) Calling-Station-Id = "02-00-00-00-00-01"
(1) Framed-MTU = 1400
(1) NAS-Port-Type = Wireless-802.11
(1) Connect-Info = "CONNECT 11Mbps 802.11b"
(1) EAP-Message = 0x0200000e01616e6f6e796d6f7573
(1) Message-Authenticator = 0x08e16ae9e6233a386ae4de4296f6b118
(1) Running section authorize from file /usr/local/freeradius/etc/raddb/sites-enabled/default
(1) authorize {
(1) eap - Peer sent EAP Response (code 2) ID 0 length 14
(1) eap - Peer sent EAP-Identity. Returning 'ok' so we can short-circuit the rest of authorize
(1) eap (ok)
(1) } # authorize (ok)
(1) Using 'Auth-Type = eap' for authenticate {...}
(1) Running Auth-Type eap from file /usr/local/freeradius/etc/raddb/sites-enabled/default
(1) authenticate {
(1) eap - Peer sent packet with EAP method Identity (1)
(1) eap - Calling submodule eap_peap to process data
(1) eap_peap - Initiating new TLS session
(1) eap - Sending EAP Request (code 1) ID 1 length 6
(1) eap (handled)
(1) } # authenticate (handled)
(1) Using Post-Auth-Type Challenge
(1) Post-Auth-Type sub-section not found. Ignoring.
(1) Running Post-Auth-Type Challenge from file /usr/local/freeradius/etc/raddb/sites-enabled/default
(1) Sent Access-Challenge Id 0 from 127.0.0.1:1812 to 127.0.0.1:52963 via lo0 length 0
(1) EAP-Message = 0x010100061920
(1) Message-Authenticator = 0x00000000000000000000000000000000
(1) State = 0x0101c700126c6ab4c489c65ec7b88ebe
(1) Finished request
Waking up in 4.9 seconds.
(2) Received Access-Request Id 1 from 127.0.0.1:52963 to 127.0.0.1:1812 via lo0 length 445
(2) User-Name = "anonymous"
(2) NAS-IP-Address = 127.0.0.1
(2) Calling-Station-Id = "02-00-00-00-00-01"
(2) Framed-MTU = 1400
(2) NAS-Port-Type = Wireless-802.11
(2) Connect-Info = "CONNECT 11Mbps 802.11b"
(2) EAP-Message = 0x0201013919800000012f160301012a010001260303c887b579a289f020b83a7d919316267d5c0d426fd99bf0c7fcde066d259344760000acc030c02cc028c024c014c00a00a500a300a1009f006b006a0069006800390038003700360088008700860085c032c02ec02ac026c00fc005009d003d00350084c02fc02bc027c023c013c00900a400a200a0009e00670040003f003e0033003200310030009a0099009800970045004400430042c031c02dc029c025c00ec004009c003c002f009600410007c011c007c00cc00200050004c012c008001600130010000dc00dc003000a00ff01000051000b000403000102000a001c001a00170019001c001b0018001a0016000e000d000b000c0009000a000d0020001e060106020603050105020503040104020403030103020303020102020203000f000101
(2) State = 0x0101c700126c6ab4c489c65ec7b88ebe
(2) Message-Authenticator = 0x3520f3dcf56a5e163e2f257b1534376d
(2,1) Running section authorize from file /usr/local/freeradius/etc/raddb/sites-enabled/default
(2,1) authorize {
(2,1) eap - Peer sent EAP Response (code 2) ID 1 length 313
(2,1) eap - Continuing tunnel setup
(2,1) eap (ok)
(2,1) } # authorize (ok)
(2,1) Using 'Auth-Type = eap' for authenticate {...}
(2,1) Running Auth-Type eap from file /usr/local/freeradius/etc/raddb/sites-enabled/default
(2,1) authenticate {
(2,1) eap - Peer sent packet with EAP method PEAP (25)
(2,1) eap - Calling submodule eap_peap to process data
(2,1) eap_peap - Continuing EAP-TLS
(2,1) eap_peap - Peer indicated complete TLS record size will be 303 bytes
(2,1) eap_peap - Got complete TLS record, with length field (303 bytes)
(2,1) eap_peap - [eap-tls verify] = complete
(2,1) eap_peap - Handshake state - before/accept initialization
(2,1) eap_peap - Handshake state - Server before/accept initialization
(2,1) eap_peap - <<< recv handshake [length 298], client_hello
(2,1) eap_peap - Handshake state - Server SSLv3 read client hello A
(2,1) eap_peap - >>> send handshake [length 94], server_hello
(2,1) eap_peap - Handshake state - Server SSLv3 write server hello A
(2,1) eap_peap - >>> send handshake [length 2259], certificate
(2,1) eap_peap - Handshake state - Server SSLv3 write certificate A
(2,1) eap_peap - >>> send handshake [length 333], server_key_exchange
(2,1) eap_peap - Handshake state - Server SSLv3 write key exchange A
(2,1) eap_peap - >>> send handshake [length 4], server_hello_done
(2,1) eap_peap - Handshake state - Server SSLv3 write server done A
(2,1) eap_peap - Handshake state - Server SSLv3 flush data
(2,1) eap_peap - Handshake state - Server SSLv3 read client certificate A
(2,1) eap_peap - Need more data from client
(2,1) eap_peap - Need more data from client
(2,1) eap_peap - Complete TLS record (2710 bytes) larger than MTU (990 bytes), will fragment
(2,1) eap_peap - Sending first TLS record fragment (990 bytes), 1720 bytes remaining
(2,1) eap_peap - [eap-tls process] = handled
(2,1) eap - Sending EAP Request (code 1) ID 2 length 1000
(2,1) eap (handled)
(2,1) } # authenticate (handled)
(2,1) Using Post-Auth-Type Challenge
(2,1) Post-Auth-Type sub-section not found. Ignoring.
(2,1) Running Post-Auth-Type Challenge from file /usr/local/freeradius/etc/raddb/sites-enabled/default
(2,1) Sent Access-Challenge Id 1 from 127.0.0.1:1812 to 127.0.0.1:52963 via lo0 length 0
(2,1) EAP-Message = 0x010203e819c000000a96160303005e0200005a0303f999c5c1765fdd98d1a90ae98ca5a44cc425b9398a8cc88146a55814235bdf3e20eb1ede90c8c7e900c176e8e74bd18822c015f76b09cfa73cd7a4094ded01aedfc030000012ff01000100000b000403000102000f00010116030308d30b0008cf0008cc0003de308203da308202c2a003020102020101300d06092a864886f70d01010b0500308193310b3009060355040613024652310f300d06035504080c065261646975733112301006035504070c09536f6d65776865726531153013060355040a0c0c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e6f72673126302406035504030c1d4578616d706c6520436572746966696361746520417574686f72697479301e170d3136303430393030343431355a170d3136303630383030343431355a307c310b3009060355040613024652310f300d06035504080c0652616469757331153013060355040a0c0c4578616d706c6520496e632e3123302106035504030c1a4578616d706c65205365727665722043657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e6f726730820122300d06092a864886f70d01010105000382010f003082010a0282010100d7da0664390c5f5919cf10809f2bebb59145fd75d486878d1d45f2c86d5ba3477b29b75bba55023fe8dffdbf8ce477b4e3ba51c04792c58d010d15b06393082bb5ec57b203cbd6bd7bc6b486e1cff66e0228b1787f5ed3e9b4d0580ea47229e8010f515e9a3786ce5b7f3b1033e04a0c5b0371722fe327d35e968590fac06ec253a646a6adb98eb151551d213057bfa25250d9f4c70c938a9074a6e369bc10929bd57c7a510b558619072ce40bd436015ebe53d7fb0a1759becec6dbe203ff7869769863154db74cf34fb9669578a56fd97260ab7d4d9fd73d23ed0b528c69334d8c164b449635b5dbe15987df3e25ff1e0377d28d3bd57bfe5aef663719b77d0203010001a34f304d30130603551d25040c300a06082b0601050507030130360603551d1f042f302d302ba029a0278625687474703a2f2f7777772e6578616d706c652e636f6d2f6578616d706c655f63612e63726c300d06092a864886f70d01010b05000382010100884dc686e71063e754aea8a5fe44098ce2353e3c4f034868630d9d77395c867b4e26b8af91557da0152a19e6797379494b11497c7bd5505c8929ea2224166a64c6998683f500483ccd4937aa4ef8ffbc868e328424ab835895a85861c143e6a45af71d79ccbe4d5f84470133ba0ae587b2ced91c53adeb69a3e26d5991fd2f06fa86259ba3aba4c4330190a9e497
(2,1) Message-Authenticator = 0x00000000000000000000000000000000
(2,1) State = 0x0203c7008a97c29ac489c65ec7b88ebe
(2,1) Finished request
Waking up in 4.9 seconds.
(3) Received Access-Request Id 2 from 127.0.0.1:52963 to 127.0.0.1:1812 via lo0 length 136
(3) User-Name = "anonymous"
(3) NAS-IP-Address = 127.0.0.1
(3) Calling-Station-Id = "02-00-00-00-00-01"
(3) Framed-MTU = 1400
(3) NAS-Port-Type = Wireless-802.11
(3) Connect-Info = "CONNECT 11Mbps 802.11b"
(3) EAP-Message = 0x020200061900
(3) State = 0x0203c7008a97c29ac489c65ec7b88ebe
(3) Message-Authenticator = 0xac16834a3bedcda9294764381e488fcb
(3,1) Running section authorize from file /usr/local/freeradius/etc/raddb/sites-enabled/default
(3,1) authorize {
(3,1) eap - Peer sent EAP Response (code 2) ID 2 length 6
(3,1) eap - Continuing tunnel setup
(3,1) eap (ok)
(3,1) } # authorize (ok)
(3,1) Using 'Auth-Type = eap' for authenticate {...}
(3,1) Running Auth-Type eap from file /usr/local/freeradius/etc/raddb/sites-enabled/default
(3,1) authenticate {
(3,1) eap - Peer sent packet with EAP method PEAP (25)
(3,1) eap - Calling submodule eap_peap to process data
(3,1) eap_peap - Continuing EAP-TLS
(3,1) eap_peap - Peer ACKed our handshake fragment
(3,1) eap_peap - [eap-tls verify] = request
(3,1) eap_peap - Sending additional TLS record fragment (994 bytes), 726 bytes remaining
(3,1) eap_peap - [eap-tls process] = handled
(3,1) eap - Sending EAP Request (code 1) ID 3 length 1000
(3,1) eap (handled)
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 842 bytes
Desc: Message signed with OpenPGP using GPGMail
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20160422/2c5acec7/attachment.sig>
More information about the Freeradius-Users
mailing list