FOTA update: at_cmd calls recv before download_client has a chance to call recv?

I am working on firmware for a custom board with an nRF9160. Specifically, I'm trying to get FOTA updates working, using the provided library functions for it. I had no issues running the sample FOTA update application on an nRF9160DK. I'm using essentially the same procedure as the sample on my custom board's program: submitting a work item when a signal is received, and calling fota_download_start when the work callback is received.

It seems that, after download_client_start is called, the at_cmd thread runs before the download_client thread, as it has higher priority. The at_cmd thread calls recv, getting the first fragment. Then when the download_client thread is given a chance to call recv, there's no more data to receive and the function doesn't return until timing out. I am not sure if this is the intended sequence of events, or something is going wrong. Does it seem like this would be a configuration issue?

The headers and first few bytes of the file get printed through the notification handler. Using the debugger to inspect the AT cmd buffer, I can see that the http headers and fragment are present (printing stops on the first zero byte of course). This is what I was seeing logged in the terminal earlier:

[00:08:28.451,416] <inf> download_client: Configuring socket timeout (120 s)
[00:08:28.455,535] <inf> download_client: Connecting to <our website>
[00:11:26.418,762] <inf> download_client: Downloading: firmware?version=0.0.1 [0]
[00:11:29.493,225] <dbg> at_monitor.at_monitor_task: AT notif: +CSCON: 0

[00:11:29.497,222] <dbg> at_monitor.at_monitor_task: Dispatching to 0x2edb5
[00:11:29.501,403] <dbg> at_monitor.at_monitor_task: AT notif: +CSCON: 1

[00:11:29.505,371] <dbg> at_monitor.at_monitor_task: Dispatching to 0x2edb5
[00:11:29.509,582] <dbg> at_monitor.at_monitor_task: AT notif: +CSCON: 0

[00:11:29.513,549] <dbg> at_monitor.at_monitor_task: Dispatching to 0x2edb5
HTTP/1.1 206 Partial Content
Content-Length: 1024
Content-Type: application/octet-stream4
Content-Range: bytes 0-1023/228839
Accept-Ranges: bytes
Server: Microsoft-IIS/10.0
Content-Disposition: attachment; filename=app_update.bin; filename*=UTF-8''app_update.bin
X-Powered-By: ASP.NET
Date: Thu, 16 Jun 2022 17:09:51 GMT

=¸ó[00:11:57.741,607] <err> at_cmd: AT message empty
[00:12:02.742,248] <err> at_cmd: AT socket recv failed with err 104

Now, I'm getting this error instead of the AT cmd ones:

[00:03:43.071,319] <err> download_client: Error in recv(), errno 116

  • Great! Glad to hear it.

    brad_57 said:

    Thank you for your time and assistance,

    Hehe no problem, though I don't think I've helped you that much.

    When it comes to this speed difference, you could try to compare the logs of the two and see where things are delayed. 

    And I would also check if you are seeing the same thing on the DK to make sure that the HW doesn't have anything to do with it, though as long as you compare using the same board this is probably ok.

    Regards,

    Elfving

Related