This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

"Server did not honor partial content request"

Hey DZ,

I'm having some trouble with the download_client. It's not playing nice with the HTTP server I'm using. On the last chunk of data, the nRF91 is issuing a Content-Range that doesn't always play nice with all server implementations. The server I'm using is returning a 416 error. 

Here's the progress from the embedded side:

2021-03-09T02:02:42.279Z DEBUG modem << [00:01:00.078,948] [0m<inf> download_client: Downloaded 194560/200595 bytes (96%)[0m
2021-03-09T02:02:42.760Z DEBUG modem << [00:01:00.558,929] [0m<inf> download_client: Downloaded 196608/200595 bytes (98%)[0m
2021-03-09T02:02:43.135Z DEBUG modem << [00:01:00.934,387] [0m<inf> download_client: Downloaded 198656/200595 bytes (99%)[0m
2021-03-09T02:02:43.529Z DEBUG modem << [00:01:01.325,347] [1;31m<err> download_client: Server did not honor partial content request[0m
2021-03-09T02:02:43.558Z DEBUG modem << [00:01:01.335,388] [1;31m<err> fota_download: Download client error[0m
2021-03-09T02:02:43.559Z DEBUG modem << [00:01:01.341,766] [0m<inf> dfu_target_mcuboot: MCUBoot image upgrade aborted.[0m

Here's the log from the HTTP server.

{"level":"info","ts":1615255361.8753276,"logger":"http.log.access","msg":"handled request","request":{"remote_addr":"52.12.23.139:64562","proto":"HTTP/1.1","method":"GET","host":"pyrinas-dev-ota.jaredwolff.com","uri":"/images/352656102712240.bin","headers":{"Range":["bytes=196608-198655"],"Connection":["keep-alive"]},"tls":{"resumed":false,"version":771,"cipher_suite":49162,"proto":"","proto_mutual":true,"server_name":"pyrinas-dev-ota.jaredwolff.com"}},"common_log":"52.12.23.139 - - [09/Mar/2021:02:02:41 +0000] \"GET /images/352656102712240.bin HTTP/1.1\" 206 2048","duration":0.00488638,"size":2048,"status":206,"resp_headers":{"Accept-Ranges":["bytes"],"Last-Modified":["Tue, 09 Mar 2021 01:50:16 GMT"],"Server":["Caddy"],"Date":["Tue, 09 Mar 2021 02:02:40 GMT"],"Content-Range":["bytes 196608-198655/200595"],"Content-Length":["2048"],"Content-Type":["application/octet-stream"]}}
{"level":"error","ts":1615255362.3557446,"logger":"http.log.access","msg":"handled request","request":{"remote_addr":"52.12.23.139:64562","proto":"HTTP/1.1","method":"GET","host":"pyrinas-dev-ota.jaredwolff.com","uri":"/images/352656102712240.bin","headers":{"Range":["bytes=198656-200595"],"Connection":["keep-alive"]},"tls":{"resumed":false,"version":771,"cipher_suite":49162,"proto":"","proto_mutual":true,"server_name":"pyrinas-dev-ota.jaredwolff.com"}},"common_log":"52.12.23.139 - - [09/Mar/2021:02:02:42 +0000] \"GET /images/352656102712240.bin HTTP/1.1\" 416 0","duration":0.00314682,"size":0,"status":416,"resp_headers":{"Content-Length":["0"],"Date":["Tue, 09 Mar 2021 02:02:42 GMT"],"Server":["Caddy"],"Content-Range":["bytes */200595"]}}

Are there any workarounds for this? I'm downloading a FOTA update so there's a need for the payload size to be fixed. (Currently set to 2048)

Thank you!

Jared

  • Looks like if I try to do this manually it also fails:

    curl https://pyrinas-dev-ota.jaredwolff.com/images/352656102712240.bin -H "Content-Type: application/octet-stream" -H "Range: bytes=198656-200595" --output bob.bin

    If I decrease the size by one byte it retrieves the last 1939 bytes

    curl https://pyrinas-dev-ota.jaredwolff.com/images/352656102712240.bin -H "Content-Type: application/octet-stream" -H "Range: bytes=198656-200594" --output bob.bin

    Seems like a bug in the implementation on Caddy whereas the byte count is indexed from 0 instead of starting at 1. Not 100% sure but I'll play with it some more..

    Update:

    Trying something similar where it's statically hosted doesn't fail. That would lead me to think that there's an issue one step lower in the stack.

    curl  https://www.jaredwolff.com/testing-hardware-using-rust/images/Screen_Shot_2021-01-06_at_10.30.55_AM.png -H "Range: bytes=125801-125808" --output test.bin

  • So after playing with the issue more, it appears that the HTTP client, when requesting the range, is requesting a range that is not indexed from 0. 

    I wrote up a full bug report on the server only to review their tests and other HTTP implementation notes to understand this better.

    If this is true I should be able to modify the requested size for the last chunk in the FOTA library. Will check to be sure.

  • Hi Jared,

     

    Jared said:

    So after playing with the issue more, it appears that the HTTP client, when requesting the range, is requesting a range that is not indexed from 0. 

    I wrote up a full bug report on the server only to review their tests and other HTTP implementation notes to understand this better.

    If this is true I should be able to modify the requested size for the last chunk in the FOTA library. Will check to be sure.

    Great job! This is impressive debugging work. Let me know if you think it might be related to how we do partial requests.

     

    Kind regards,

    Håkon

  • Honestly, I think the MFW is doing exactly what it should be. I've tried the same type of request on other HTTP servers and all worked ok. Seems like the implementation in warp doesn't cover the edge case if the end byte count == file size it shouldn't bork.

    I haven't heard back from the main dev, not sure if I will, I may just roll with a patched version of warp for now. Thanks for your help!

  • This has been patched in warp. I think is a corner case in the HTTP specification that is not very well defined. It's been working great over the past two months since it was implemented! Here's the PR: github.com/.../818

Related