REST POST buffer overflow
We are running 3.0.15 and are seeing occasional issues when a large accounting packet is passed to our REST server: It appears that a buffers gets a bit full and if this occurs when an attribute name is written, but not the value, the next chunk starts with the value of the NEXT AVP instead of the one that was being processed when the buffer got full: Here is some debug I captured (various values obfuscated) : Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Length : 1 Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Value : 0 Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Encoding attribute "Calling-Station-Id" Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Length : 17 Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Value : aa-bb-cc-dd-ee-ff Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Encoding attribute "Called-Station-Id" Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Length : 26 Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Value : AAAA-BBBB-CC-DDDD%3A_EEEE-FF Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: POST Data: User-Name=ccccccc%2F2-e0f81c520daf44eba1335f1c508b65d2-form%4014143d&NAS-Port=8&NAS-IP-Address=10.101.0.2&Framed-IP-Address=10.101.16.156&Class=0x62746f7a2d2d2d35666664356238612f37303a62633a31303a36383a32373a65322f31333938323736392f313631303433393537342d2d2d&Class=0x52454749442166383534626439392d613335652d343033302d613331632d623632333837363535373866&NAS-Identifier=ccccccccc%2F&Airespace-Wlan-Id=90&Acct-Session-Id=5ffd5b8a%2F70%3Abc%3A10%3A68%3A27%3Ae2%2F13982769&NAS-Port-Type=Wireless-802.11&Cisco-AVPair=audit-session-id%3D980027d9008b75188a5bfd5f&Acct-Authentic=RADIUS&Tunnel-Type=VLAN&Tunnel-Medium-Type=IEEE-802&Tunnel-Private-Group-Id=2566&Event-Timestamp=Jan%2012%202021%2012%3A31%3A05%20GMT&Acct-Status-Type=Interim-Update&Acct-Input-Octets=2714442414&Acct-Input-Gigawords=0&Acct-Output-Octets=1012626742&Acct-Output-Gigawords=0&Acct-Input-Packets=3975169&Acct-Output-Packets=2035021&Acct-Session-Time=15090&Acct-Delay-Time=0&Calling-Station-Id=aa-bb-cc-dd-ee-ff&Called-Station-Id= Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Returning 995 bytes of POST data (buffer full or chunk exceeded) Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Encoding attribute "Tmp-String-9" Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Length : 3 Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Value : ai%3A Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Encoding attribute "Acct-Unique-Session-Id" Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Length : 32 Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: POST Data: ai%3A&Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736 Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Returning 61 bytes of POST data Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Processing response header Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Status : 100 () Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Continuing... Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Processing response header Tue Jan 12 12:31:05 2021 : Debug: (53749687) rest: Status : 200 () Is this something that would fix if we upgrade to 3.0.21 or a bug that could be fixed? TIA Adrian
On Jan 12, 2021, at 1:48 PM, adrian.p.smith@bt.com wrote:
We are running 3.0.15 and are seeing occasional issues when a large accounting packet is passed to our REST server:
It appears that a buffers gets a bit full and if this occurs when an attribute name is written, but not the value, the next chunk starts with the value of the NEXT AVP instead of the one that was being processed when the buffer got full:
That code is ~9 years old and I believe you're the first person to hit that bug, congratulations! It happens when the value has been written, there's no bytes remaining in the output buffer, and there are more attributes to encode. Which may not sound that uncommon, but the length of the value needs to fit perfectly in the output buffer in order for this to happen. The correct fix is to add an encoding state to represent the separator '&', but I don't want to accidentally break anything else. The bad but functional fix is to check if we can write the separator before advancing the pair cursor. https://github.com/FreeRADIUS/freeradius-server/commit/3dd36aa1058343e3e7a99... With the fix applied you'll notice that the debug output indicates the value has been encoded twice, but in reality it'll only occur in the POST data once. Because that code has been stable for so long you might just be able to apply the diff directly to 3.0.15, or you can wait for the next stable release and upgrade. There's also a bit of a crappy work around. If you adjust the 'chunk' parameter for a given section (maybe set it to 900) you can reduce the amount of buffer that's filled before the encoding callback returns. As this is such an edgy edge case it's likely that you won't hit it with a different output buffer size. -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
Thanks for the quick response Arran. I think we will write an integration test to reproduce the issue and then decide which approach works for us. Adrian -----Original Message----- From: Freeradius-Users <freeradius-users-bounces+adrian.p.smith=bt.com@lists.freeradius.org> On Behalf Of Arran Cudbard-Bell Sent: 12 January 2021 14:36 To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Subject: Re: REST POST buffer overflow
On Jan 12, 2021, at 1:48 PM, adrian.p.smith@bt.com wrote:
We are running 3.0.15 and are seeing occasional issues when a large accounting packet is passed to our REST server:
It appears that a buffers gets a bit full and if this occurs when an attribute name is written, but not the value, the next chunk starts with the value of the NEXT AVP instead of the one that was being processed when the buffer got full:
That code is ~9 years old and I believe you're the first person to hit that bug, congratulations! It happens when the value has been written, there's no bytes remaining in the output buffer, and there are more attributes to encode. Which may not sound that uncommon, but the length of the value needs to fit perfectly in the output buffer in order for this to happen. The correct fix is to add an encoding state to represent the separator '&', but I don't want to accidentally break anything else. The bad but functional fix is to check if we can write the separator before advancing the pair cursor. https://eur02.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2FFreeRADIUS%2Ffreeradius-server%2Fcommit%2F3dd36aa1058343e3e7a99ca29ffaae4c172748e1&data=04%7C01%7Cadrian.p.smith%40bt.com%7C846324fd74e54102233d08d8b70774ed%7Ca7f356889c004d5eba4129f146377ab0%7C0%7C0%7C637460590378734877%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=2rOuggVWPCziI7pymMwMuK5ioGKtNadU09CpedXr9i4%3D&reserved=0 With the fix applied you'll notice that the debug output indicates the value has been encoded twice, but in reality it'll only occur in the POST data once. Because that code has been stable for so long you might just be able to apply the diff directly to 3.0.15, or you can wait for the next stable release and upgrade. There's also a bit of a crappy work around. If you adjust the 'chunk' parameter for a given section (maybe set it to 900) you can reduce the amount of buffer that's filled before the encoding callback returns. As this is such an edgy edge case it's likely that you won't hit it with a different output buffer size. -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
I have created a re-producible integration test and tried the suggested patch on 3.0.15 and 3.0.21 but unfortunately it seems to make things worse (or at least different). Here is some debug from 3.0.21 (some values obfuscated) Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Delay-Time" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 1 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 0 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Calling-Station-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 17 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 70-bc-10-68-27-e2 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Called-Station-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 26 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : WBRM-WBWD-01-AP02%3A_XXXX Thu Jan 21 10:26:01 2021 : Debug: (1) rest: POST Data: User-Name=XXXX%2F2-e0f81c520daf44eba1335f1c508b65d2-form%4014143d&NAS-Port=8&NAS-IP-Address=10.101.0.2&Framed-IP-Address=10.101.16.156&Class=0x62746f7a2d2d2d35666664356238612f37303a62633a31303a36383a32373a65322f31333938323736392f313631303433393537342d2d2d&Class=0x52454749442166383534626439392d613335652d343033302d613331632d623632333837363535373866&NAS-Identifier=cloudwifi%2F&Airespace-Wlan-Id=90&Acct-Session-Id=5ffd5b8a%2F70%3Abc%3A10%3A68%3A27%3Ae2%2F13982769&NAS-Port-Type=Wireless-802.11&Cisco-AVPair=audit-session-id%3D980027d9008b75188a5bfd5f&Acct-Authentic=RADIUS&Tunnel-Type=VLAN&Tunnel-Medium-Type=IEEE-802&Tunnel-Private-Group-Id=2566&Event-Timestamp=Jan%2012%202021%2012%3A31%3A05%20GMT&Acct-Status-Type=Interim-Update&Acct-Input-Octets=2714442414&Acct-Input-Gigawords=0&Acct-Output-Octets=1012626742&Acct-Output-Gigawords=0&Acct-Input-Packets=3975169&Acct-Output-Packets=2035021&Acct-Session-Time=15090&Acct-Delay-Time=0&Calling-Station-Id=70-bc-10-68-27-e2&Called-Station-Id= Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Returning 995 bytes of POST data (buffer full or chunk exceeded) Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Called-Station-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 26 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : WBRM-WBWD-01-AP02%3A_XXXX Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Attr-105" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 66 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 0x3863323239616163376464326137666666396466306235313238643961373336 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Tmp-String-9" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 3 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : ai%3A Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: POST Data: WBRM-WBWD-01-AP02%3A_XXXX&Attr-105=0x3863323239616163376464326137666666396466306235313238643961373336&Tmp-String-9=ai%3A&Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id= Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Returning 1027 bytes of POST data (buffer full or chunk exceeded) Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: POST Data: 8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736Acct-Unique-Session-Id=8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Returning 2067 bytes of POST data (buffer full or chunk exceeded) Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Length : 32 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Value : 8c229aac7dd2a7fff9df0b5128d9a736 Thu Jan 21 10:26:01 2021 : Debug: (1) rest: Encoding attribute "Acct-Unique-Session-Id" -----Original Message----- From: Freeradius-Users <freeradius-users-bounces+adrian.p.smith=bt.com@lists.freeradius.org> On Behalf Of adrian.p.smith@bt.com Sent: 12 January 2021 15:02 To: freeradius-users@lists.freeradius.org Subject: RE: REST POST buffer overflow Thanks for the quick response Arran. I think we will write an integration test to reproduce the issue and then decide which approach works for us. Adrian -----Original Message----- From: Freeradius-Users <freeradius-users-bounces+adrian.p.smith=bt.com@lists.freeradius.org> On Behalf Of Arran Cudbard-Bell Sent: 12 January 2021 14:36 To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org> Subject: Re: REST POST buffer overflow
On Jan 12, 2021, at 1:48 PM, adrian.p.smith@bt.com wrote:
We are running 3.0.15 and are seeing occasional issues when a large accounting packet is passed to our REST server:
It appears that a buffers gets a bit full and if this occurs when an attribute name is written, but not the value, the next chunk starts with the value of the NEXT AVP instead of the one that was being processed when the buffer got full:
That code is ~9 years old and I believe you're the first person to hit that bug, congratulations! It happens when the value has been written, there's no bytes remaining in the output buffer, and there are more attributes to encode. Which may not sound that uncommon, but the length of the value needs to fit perfectly in the output buffer in order for this to happen. The correct fix is to add an encoding state to represent the separator '&', but I don't want to accidentally break anything else. The bad but functional fix is to check if we can write the separator before advancing the pair cursor. https://eur02.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2FFreeRADIUS%2Ffreeradius-server%2Fcommit%2F3dd36aa1058343e3e7a99ca29ffaae4c172748e1&data=04%7C01%7Cadrian.p.smith%40bt.com%7Ca177b816d728493b8df108d8b70b25b4%7Ca7f356889c004d5eba4129f146377ab0%7C0%7C0%7C637460605790382736%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C1000&sdata=JsG%2BIs3GU6uf71RvRpboIWrifhciinCQNRAAWlSdyvo%3D&reserved=0 With the fix applied you'll notice that the debug output indicates the value has been encoded twice, but in reality it'll only occur in the POST data once. Because that code has been stable for so long you might just be able to apply the diff directly to 3.0.15, or you can wait for the next stable release and upgrade. There's also a bit of a crappy work around. If you adjust the 'chunk' parameter for a given section (maybe set it to 900) you can reduce the amount of buffer that's filled before the encoding callback returns. As this is such an edgy edge case it's likely that you won't hit it with a different output buffer size. -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2 - List info/subscribe/unsubscribe? See https://eur02.safelinks.protection.outlook.com/?url=http%3A%2F%2Fwww.freeradius.org%2Flist%2Fusers.html&data=04%7C01%7Cadrian.p.smith%40bt.com%7Ca177b816d728493b8df108d8b70b25b4%7Ca7f356889c004d5eba4129f146377ab0%7C0%7C0%7C637460605790392697%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C1000&sdata=Z8soPjqNs9yNRn6pWiygYltsKP5Unh2bUtyqta6H89U%3D&reserved=0
On Jan 21, 2021, at 10:41 AM, adrian.p.smith@bt.com wrote:
I have created a re-producible integration test and tried the suggested patch on >>3.0.15 and 3.0.21 but unfortunately it seems to make things worse (or at least >>different).
Pushed another fix.
-Arran
Is it this commit? https://github.com/FreeRADIUS/freeradius-server/commit/12b6ea41e920e2aab1347... Adrian
Adrian, The patch mentioned by Arran is https://github.com/FreeRADIUS/freeradius-server/commit/0392263b753421069b56c... <https://github.com/FreeRADIUS/freeradius-server/commit/0392263b753421069b56c7c6351455985d5bacfd> -- Jorge Pereira jpereira@freeradius.org
Em 22 de jan de 2021, à(s) 15:17, adrian.p.smith@bt.com escreveu:
On Jan 21, 2021, at 10:41 AM, adrian.p.smith@bt.com wrote:
I have created a re-producible integration test and tried the suggested patch on >>3.0.15 and 3.0.21 but unfortunately it seems to make things worse (or at least >>different).
Pushed another fix.
-Arran
Is it this commit? https://github.com/FreeRADIUS/freeradius-server/commit/12b6ea41e920e2aab1347...
Adrian
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
https://github.com/FreeRADIUS/freeradius-server/commit/0392263b753421069b56c...
Awesome. I can confirm that this fixes our 3.0.15 and 3.0.21 builds. Regards, Adrian
On Jan 23, 2021, at 4:54 PM, adrian.p.smith@bt.com wrote:
https://github.com/FreeRADIUS/freeradius-server/commit/0392263b753421069b56c...
Awesome.
I can confirm that this fixes our 3.0.15 and 3.0.21 builds.
Thanks for testing/confirming :) -Arran
participants (3)
-
adrian.p.smith＠bt.com -
Arran Cudbard-Bell -
Jorge Pereira