C HTTP post request getting a second response (400 Bad Request) after first 200 OK

Question

I've been struggling with this issue for a while so it's time to ask for help.

System: nRF9160 microcontroller running Zephyr RTOS using cellular modem to post to endpoints running on GCP

Problem:

I am using Zephyr's socket functions (which are matched to the BSD spec I believe) to send post requests like so (see below). I use the cJSON library to package up the payload and then to parse the payload from the response.
This works perfectly end-to-end when I have "connection: close" and only am trying to send one heartbeat at a time. I get a 200 OK from the server all is as expected.
However if I try to keep the socket connection open with a "keep-alive" in the header and then perform the send and receive multiple times then I get a strange response: first a 200 OK, followed immediately by a 400 Bad Request all from the same POST.

Heartbeat send function

int err;
LOG_INF("Open socket");
fd = socket(AF_INET, SOCK_STREAM, IPPROTO_TLS_1_2); // Error code: 9
if (fd == -1)
{
    LOG_ERR("Failed to open socket!");
    clean_up();
}

/* Setup TLS socket options */
err = tls_setup(fd); // Error code: 7
if (err)
{
    LOG_ERR("TLS cert failure");
    clean_up();
}

// 12sec timeout for send + receive socket
socket_send_timeout(fd, 12000);
socket_recv_timeout(fd, 12000);

LOG_INF("Connecting to %s", "our.api.endpoint.com"); // us
err = connect(fd, res->ai_addr, sizeof(struct sockaddr_in)); // Error code: 10
if (err)
{
    LOG_ERR("connect() failed, err: %d", errno);
    return clean_up();
}

// [1] Empty the send buffer
memset(send_buffer, 0, sizeof(send_buffer));

// [2] Set up endpoint -> 'heartbeat'
sprintf(command, "%s", "heartbeat");

// [3] Route builder
// POST /devices/'this device'/heartbeat HTTP/1.1
// Host: our.api.endpoint.com:443
// Authorization: Bearer "auth_token"
// Connection: keep-alive
// Content-Type: application/json
// Content-Length:
sprintf(send_buffer, "%s", "POST /devices/");
strcat(send_buffer, deviceName);
strcat(send_buffer, "/");
strcat(send_buffer, command);
strcat(send_buffer, " HTTP/1.1\r\n");
strcat(send_buffer, "Host: our.api.endpoint.com:443\r\n");
strcat(send_buffer, "Authorization: Bearer ");
strcat(send_buffer, token); // Token is read from flash and stored globally
strcat(send_buffer, "\r\nConnection: keep-alive\r\n");
strcat(send_buffer, "Content-Type: application/json\r\n");
strcat(send_buffer, "Content-Length: ");

// [4] Build payload
// { "ip_address":   "172.0.0.0" }

cJSON_Init();
char *out;
cJSON *ip_address = NULL;

// Todo: Create IP string, need to implement real check here
if (modem_ip_address != NULL) {
    ip_address = cJSON_CreateString(modem_ip_address);
}
else {
    ip_address = cJSON_CreateString("Undefined modem_ip_address");
}

// create JSON root object
cJSON *root = cJSON_CreateObject();

//add fields to JSON
cJSON_AddItemToObject(root, "ip_address", ip_address);

//Print full complete JSON object
out = cJSON_Print(root);

// [5] Content-length calculate
static char len[8];
sprintf(len, "%d", strlen(out));
strcat(send_buffer, len);
strcat(send_buffer, "\r\n\r\n");

//Add JSON to request
strcat(send_buffer, out);

free(out);
cJSON_Delete(root);
int success = 0;
int num_times = 3;
for (int i = 1; i <= num_times; i++) {
    //sending request
    LOG_INF("Sending Request %d of %d", i, num_times);
    off = 0;
    LOG_INF(" -----[SEND BUFFER]-----");
    printk("%s\n", send_buffer);
    LOG_INF(" -----[BUFFER END]-----");
    do
    {
        bytes = send(fd, &send_buffer[off], sizeof(send_buffer) - off, 0); // Error code: 11
        if (bytes < 0)
        {
            LOG_ERR("send() failed, err %d", errno);
            return clean_up();
        }
        off += bytes;
    } while (off < sizeof(send_buffer) - 1);

    LOG_INF("--> Sent %d bytes", off);
    // memset(send_buffer, 0, sizeof(send_buffer));
    off = 0;
    do
    {
        bytes = recv(fd, &recv_buf[off], BUF_SIZE - off, 0);
        if (bytes < 0)
        {
            LOG_ERR("recv() failed, err %d", errno); // Error code: 12
            return clean_up();
        }
        off += bytes;
        LOG_INF("--> %d B", off);
    } while (bytes != 0 /* peer closed connection */);


    LOG_INF("----> Received %d bytes", off);
    LOG_INF(" -----[HTTP RESPONSE]-----");
    success = parse_http_ret_code(recv_buf); // return 1 if 200, return 0 otherwise
    if (success) {
        sprintf(json, strchr(recv_buf, '{'));
        printk("%s\n", json);
        success &= parse_heartbeat_response(json);
    }
    LOG_INF(" -----[HTTP END]-----");
    // TODO
    // Add error code return status so we can use that in server controller
    memset(recv_buf, 0, sizeof(recv_buf));
    memset(json, 0, sizeof(json));
}
memset(send_buffer, 0, sizeof(send_buffer));
close(fd);
return success;

Post with Keep-Alive: 200 OK, followed by 400 Bad Request

[00:00:12.174,926] [0m<inf> networking: Sending Request 1 of 3[0m
[00:00:12.174,926] [0m<inf> networking:  -----[SEND BUFFER]-----[0m
POST /devices/device_id/heartbeat HTTP/1.1
Host: our.api.endpoint.com:443
Authorization: Bearer token-goes-here
Connection: keep-alive
Content-Type: application/json
Content-Length: 35

{"ip_address":"172.0.0.0"}
[00:00:12.175,262] [0m<inf> networking:  -----[BUFFER END]-----[0m
[00:00:12.177,459] [0m<inf> networking: --> Sent 2048 bytes[0m
[00:00:13.144,500] [0m<inf> networking: --> 651 B[0m
[00:00:13.153,015] [0m<inf> networking: --> 799 B[0m
[00:00:13.163,330] [0m<inf> networking: --> 978 B[0m
[00:00:13.163,360] [0m<inf> networking: --> 978 B[0m
[00:00:13.163,360] [0m<inf> networking: ----> Received 978 bytes[0m
[00:00:13.163,391] [0m<inf> networking:  -----[HTTP RESPONSE]-----[0m
[00:00:13.163,391] [0m<inf> networking: 200 OK[0m
{"device_string":"device_id","ip_address":"172.0.0.0","last_heartbeat_time":"Fri, 28 Jan 2022 20:53:42 GMT","status":[2,2,2,2,2,2,2,2]}
HTTP/1.0 400 Bad Request
Content-Length: 54
Content-Type: text/html; charset=UTF-8
Date: Fri, 28 Jan 2022 20:53:42 GMT

<html><title>Error 400 (Bad Request)!!1</title></html>

Post with close: only 200 OK

[00:00:29.778,015] <inf> networking:  -----[SEND BUFFER]-----
POST /device/device_id/heartbeat HTTP/1.1
Host: our.api.endpoint.com:443
Authorization: Bearer token-goes-here
Connection: close
Content-Type: application/json
Content-Length: 31

{"ip_address":"172.0.0.0"}
[00:00:29.778,350] <inf> networking:  -----[BUFFER END]-----
[00:00:29.780,578] <inf> networking: --> Sent 2047 bytes
[00:00:31.219,940] <inf> networking: --> 666 B
[00:00:31.221,282] <inf> networking: --> 818 B
[00:00:31.221,313] <inf> networking: --> 818 B
[00:00:31.221,313] <inf> networking: ----> Received 818 bytes
[00:00:31.221,313] <inf> networking:  -----[HTTP RESPONSE]-----
[00:00:31.221,343] <inf> networking: 200 OK
{"device_string":"device_id","ip_address":"172.0.0.0","last_heartbeat_time":"Thu, 27 Jan 2022 01:42:32 GMT","status":[2,2,2,2,2,2,2,2]}

This is leading me to believe I am configuring something in the HTTP header or the JSON such that the GCP load-balancer or nginx is sending back a 400 because it thinks it's seeing multiple requests. For the life of me I've tried changing everything and can't make sense of where the mistake is.

Similarly I've tried reproducing these with Postman and Curl and they function as expected with none of these chained 400s.

A few interesting points:

In the 400 Bad Request it seems to be the HTML from the default google 400 page (notice the Error 400 (Bad Request)!!1).
It also shows HTTP/1.0 for some reason even though I'm using 1.1 for my POST request

Would love anyone's thoughts here. I have a feeling it has something to do with my poor understanding of string building in C or improper usage of cJSON.

`send(fd, &send_buffer[off], sizeof(send_buffer) - off, 0); ` and `while (off < sizeof(send_buffer) - 1);` look wrong. Shouldn't it be `strlen` instead of `sizeof`? — kaylum, Jan 28 '22 at 21:40
I agree with kaylum, the code is sending too many bytes with each request, so in a `keep-alive` scenario, the server is going to treat extra bytes after the first request as if they are the next request, and is thus failing because those extra bytes are garbage. — Remy Lebeau, Jan 28 '22 at 21:47
Also, a `recv()` loop that just blindly reads until error/disconnect (as this code is using) will not work in a `keep-alive` scenario. You MUST receive the HTTP response headers up to the terminating `\r\n\r\n`, then parse the headers to discover whether a response body is present and in what format it is being transmitted, and then receive that body until the specified termination condition is reached. I've posted [many answers](https://stackoverflow.com/search?q=user%3A65863+is%3Aanswer+http+pseudo) on that very topic before. — Remy Lebeau, Jan 28 '22 at 21:49
Thanks all. I've updated the send loop per kaylum's suggestion and now the recv loop is hanging for the reason you described Remy. I'll look at your other answers about this to see how to implement a check for the termination. — Wiley Jones, Jan 28 '22 at 21:52

score 0 · Answer 1 · answered Jan 31 '22 at 19:06

If I've understood your code correctly you do multiple HTTP requests within a single TCP connection. I think you should open/close a TCP connection for each HTTP request.

Maybe Websockets would be more appropriate to your issue. Then you don't need to open a new connection for every request.

C HTTP post request getting a second response (400 Bad Request) after first 200 OK

1 Answers1