HTTP Restful Server Example Error

[BdT141]

Hi everyone,

I have been trying to get the POST part of the restful server example to work but it keeps hitting an error and rebooting. Here is my unchanged, apart from a few extra printf statements, POST handler code:

Code: Select all

/* Simple handler for light brightness control */
static esp_err_t light_brightness_post_handler(httpd_req_t *req)
{
    int total_len = req->content_len;
    int cur_len = 0;
    char *buf = ((rest_server_context_t *)(req->user_ctx))->scratch;
    int received = 0;
    if (total_len >= SCRATCH_BUFSIZE) {
        /* Respond with 500 Internal Server Error */
        httpd_resp_send_err(req, HTTPD_500_INTERNAL_SERVER_ERROR, "content too long");
        return ESP_FAIL;
    }
    printf("Length not too long...\n");
    printf("Total Length: %d\n", total_len);
    printf("Method: %d\n", req->method);
    printf("URI: %s\n", req->uri);
    while (cur_len < total_len) {
    	printf("Receiving...\n");
        received = httpd_req_recv(req, buf + cur_len, total_len);
        printf("Received: %d", received);
        if (received <= 0) {
            /* Respond with 500 Internal Server Error */
            httpd_resp_send_err(req, HTTPD_500_INTERNAL_SERVER_ERROR, "Failed to post control value");
            return ESP_FAIL;
        }
        cur_len += received;
    }
    buf[total_len] = '\0';

    cJSON *root = cJSON_Parse(buf);
    int red = cJSON_GetObjectItem(root, "red")->valueint;
    int green = cJSON_GetObjectItem(root, "green")->valueint;
    int blue = cJSON_GetObjectItem(root, "blue")->valueint;
    ESP_LOGI(REST_TAG, "\nLight control: red = %d, green = %d, blue = %d\n", red, green, blue);
    cJSON_Delete(root);
    httpd_resp_sendstr(req, "Post control value successfully");
    return ESP_OK;
}

as well as the error it gives:

Code: Select all

Length not too long...
Total Length: 24
Method: 3
URI: /api/light
Receiving...
Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.
Core 1 register dump:
PC      : 0x400d6e73  PS      : 0x00060430  A0      : 0x800deae4  A1      : 0x3ffd3650  
A2      : 0x3ffc9384  A3      : 0x00000000  A4      : 0x00000018  A5      : 0x3ffcf9f8  
A6      : 0x3ffcf9e0  A7      : 0x00000018  A8      : 0x800d6e73  A9      : 0x3ffd3630  
A10     : 0x00000000  A11     : 0x3f405500  A12     : 0x00000018  A13     : 0x3ffc99a8  
A14     : 0x0000000a  A15     : 0x00000002  SAR     : 0x00000004  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000014  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0x00000000  

ELF file SHA256: 3b43c81c49b3a82d

Backtrace: 0x400d6e70:0x3ffd3650 0x400deae1:0x3ffd36f0 0x400df2d5:0x3ffd3730 0x400df36d:0x3ffd37c0 0x400de06c:0x3ffd37e0 0x400dd968:0x3ffd3800 0x400dd9df:0x3ffd3840 0x40092eed:0x3ffd3860

I currently don't have any files in the "/api/light" folder on the SD card and the other GET request handlers all work fine.

Thanks,
Brandon

UPDATE: I changed the printfs to ESP_LOGI statements because nvannote was correct that they are handled differently and don't show. I added a few more prints to see exactly where the problem was:

Code: Select all

while(cur_len < total_len) {
    	ESP_LOGI(REST_TAG, "Beginning...");
    	ESP_LOGI(REST_TAG, "Current length before: %d", cur_len);
    	if(cur_len == total_len){
    		ESP_LOGI(REST_TAG, "The same1");
		}
    	ESP_LOGI(REST_TAG, "Receiving...");
        received = httpd_req_recv(req, buf + cur_len, total_len);
        ESP_LOGI(REST_TAG, "Received: %d", received);
        if (received <= 0) {
            /* Respond with 500 Internal Server Error */
            httpd_resp_send_err(req, HTTPD_500_INTERNAL_SERVER_ERROR, "Failed to post control value");
            return ESP_FAIL;
        }
        cur_len += received;
        ESP_LOGI(REST_TAG, "Current length after: %d", cur_len);
        ESP_LOGI(REST_TAG, "Total length after: %d", total_len);
        ESP_LOGI(REST_TAG, "Buffer after: %s", buf);
        ESP_LOGI(REST_TAG, "End...");
    }

and this is the output:

Code: Select all

[1B][0;32mI (6272) esp-rest: Beginning...[1B][0m
[1B][0;32mI (6272) esp-rest: Current length before: 0[1B][0m
[1B][0;32mI (6272) esp-rest: Receiving...[1B][0m
[1B][0;32mI (6272) esp-rest: Received: 25[1B][0m
[1B][0;32mI (6282) esp-rest: Current length after: 25[1B][0m
[1B][0;32mI (6282) esp-rest: Total length after: 25[1B][0m
[1B][0;32mI (6292) esp-rest: Buffer after: red=123&green=12&blue=100[1B][0m
[1B][0;32mI (6292) esp-rest: End...[1B][0m
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x400d6efa  PS      : 0x00060c30  A0      : 0x800deb68  A1      : 0x3ffd3650  
A2      : 0x3ffd18ac  A3      : 0x00000000  A4      : 0x00000000  A5      : 0x00000019  
A6      : 0x3ffcf050  A7      : 0x00000019  A8      : 0x800d6efa  A9      : 0x3ffd3630  
A10     : 0x00000000  A11     : 0x3f4055fc  A12     : 0x3f402f40  A13     : 0x00001894  
A14     : 0x3f402c9c  A15     : 0x3ffcf050  SAR     : 0x00000004  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000014  LBEG    : 0x4000c46c  LEND    : 0x4000c477  LCOUNT  : 0x00000000  

ELF file SHA256: b17b09d3d474528b

Backtrace: 0x400d6ef7:0x3ffd3650 0x400deb65:0x3ffd3690 0x400df359:0x3ffd36d0 0x400df3f1:0x3ffd3760 0x400de0f0:0x3ffd3780 0x400dd9ec:0x3ffd37a0 0x400dda63:0x3ffd37e0 0x40092eed:0x3ffd3800

It seems that the whole request is being read into the buffer and the current length is equal to the total length, but somewhere between reevaluting the while condition and printing "Beginning..." the error occurs, because "Beginning..." isn't printed for the second time so the http_req_recv isn't called again to do the illegal read.

[nvannote]

Code: Select all

    while (cur_len < total_len) {
    	printf("Receiving...\n");
        received = httpd_req_recv(req, buf + cur_len, total_len);
        printf("Received: %d", received);
        if (received <= 0) {
            /* Respond with 500 Internal Server Error */
            httpd_resp_send_err(req, HTTPD_500_INTERNAL_SERVER_ERROR, "Failed to post control value");
            return ESP_FAIL;
        }
        cur_len += received;
    }
    buf[total_len] = '\0';
}

This loop is suspect. It is incrementing `current length' which is an offset into the buffer, but does not decrement `total_len'. That is bound to cause `httpd_req_recv' to overrun the buffer and scribble on (or attempt to read) something it shouldn't given more than one iteration.

Seems the example is written that way.

Best Regards

EDIT:

I re-read the documentation for this httpd_req_recv. This is an odd little interface the way the documentation is written. But I did find other code within ESP-IDF which uses this API and they are certainly taking the amount already read into consideration. i.e. "total - current" in a loop.

[BdT141]

This loop is suspect. It is incrementing `current length' which is an offset into the buffer, but does not decrement `total_len'. That is bound to cause `httpd_req_recv' to overrun the buffer and scribble on something it shouldn't given more than one iteration.

Seems the example is written that way. It's a bug.

Best Regards

Yes I agree, but it seems to me it is failing on the first iteration and the buffer size is way larger than the size of the requests coming through.

[nvannote]

Yes I agree, but it seems to me it is failing on the first iteration and the buffer size is way larger than the size of the requests coming through.

As my edit above;

I re-read the documentation for this httpd_req_recv. This is an odd little interface the way the documentation is written. But I did find other code within ESP-IDF which uses this API and they are certainly taking the amount already read into consideration. i.e. "total - current" in the loop.

I am not sure what the stdio flush policy for ESP-IDF (I stick to esp_log), but your 'Received' printf doesn't have a newline and "may" not be showing up right away.

In any event, I will let someone more familiar with this API chime in. But that httpd_req_recv does stand out. My 2 cents.

Best Regards