Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

What does this mean (IDFGH-10743) #11960

Closed
3 tasks done
franz-ms-muc opened this issue Jul 26, 2023 · 5 comments
Closed
3 tasks done

What does this mean (IDFGH-10743) #11960

franz-ms-muc opened this issue Jul 26, 2023 · 5 comments
Assignees
Labels
Resolution: Done Issue is done internally Status: Done Issue is done internally

Comments

@franz-ms-muc
Copy link
Contributor

franz-ms-muc commented Jul 26, 2023

Answers checklist.

  • I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
  • I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
  • I have searched the issue tracker for a similar issue and not found a similar issue.

General issue report

running the file_serving Sample at ESP-IDF 5.1
i get this ins the Log.
Reglulary. every few seconds.

W (99191) httpd_uri: httpd_uri: Method '3' not allowed for URI '/ubus'
W (99191) httpd_txrx: httpd_resp_send_err: 405 Method Not Allowed - Specified method is invalid for this resource

what does it mean ?

@espressif-bot espressif-bot added the Status: Opened Issue is new label Jul 26, 2023
@github-actions github-actions bot changed the title What does this mean What does this mean (IDFGH-10743) Jul 26, 2023
@Pieter-Vandaele
Copy link
Contributor

At the bottom of the file_server.c file, there is a list of httpd_register_uri_handler the server responds to. If you see that line in your log, it means that the server received a message that is not part in the list.

In the example, there is HTTP_GET on all URIs (/*) and HTTP_POST on the URIs /upload/* and /delete/*.
Your logline Method 3 means HTTP_POST, but the URI /ubus is not part of the specified URI handlers. To fix, change any of the 2 present HTTP_POST handlers, or add one:

/* URI handler for deleting files from server */
    httpd_uri_t file_ubus = {
        .uri       = "/ubus",   // Match URIs of type /ubus
        .method    = HTTP_POST,
        .handler   = ubus_post_handler,
        .user_ctx  = server_data    // Pass server data as context
    };
    httpd_register_uri_handler(server, &file_ubus);

Don't forget to add the corresponding handler function if you decide to add a uri_handler

@laukik-hase
Copy link
Collaborator

Thanks for the detailed answer @Pieter-Vandaele!

Hope this helps, @franz-ms-muc!

Closing this issue.

@espressif-bot espressif-bot added Status: Done Issue is done internally Resolution: Done Issue is done internally and removed Status: Opened Issue is new labels Aug 14, 2023
@franz-ms-muc
Copy link
Contributor Author

@franz-ms-muc
Copy link
Contributor Author

looking at a verbose trace, it looks like it is coming from Chrome. 


I (68314) wifi softAP: station 00:93:37:e4:ca:37 join, AID=1
D (68321) esp_netif_lwip: esp_netif_dhcps_cb esp_netif:0x3fcb8c98
I (68326) esp_netif_lwip: DHCP server assigned IP to a client, IP is: 192.168.4.2
D (68334) esp_netif_lwip: Client's MAC: 0:93:37:e4:ca:37
D (68339) event: no handlers have been registered for event IP_EVENT:2 posted to loop 0x3fcb7d70
I (68462) wifi:<ba-add>idx:2 (ifx:1, 00:93:37:e4:ca:37), tid:0, ssn:14, winSize:64
D (68574) httpd: httpd_server: processing listen socket 54
D (68575) httpd: httpd_accept_conn: newfd = 58
D (68575) httpd_sess: httpd_sess_new: fd = 58
D (68578) httpd_sess: httpd_sess_new: active sockets: 1
D (68583) httpd: httpd_accept_conn: complete
D (68588) httpd: httpd_server: doing select maxfd+1 = 59
D (68588) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:2 posted to loop 0x3fcb7d70
D (68593) httpd: httpd_process_session: processing socket 58
D (68609) httpd_sess: httpd_sess_process: httpd_req_new
D (68614) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (68621) httpd_txrx: httpd_recv_with_opt: received length = 109
D (68626) httpd_parse: read_block: received HTTP request block size = 109
D (68633) httpd_parse: cb_url: message begin
D (68637) httpd_parse: cb_url: processing url = /ubus
D (68643) httpd_parse: verify_url: received URI = /ubus
D (68648) httpd_parse: cb_header_field: headers begin
D (68653) httpd_txrx: httpd_unrecv: length = 88
D (68658) httpd_parse: pause_parsing: paused
D (68662) httpd_parse: cb_header_field: processing field = Host
D (68668) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (68674) httpd_txrx: httpd_recv_with_opt: pending length = 88
D (68680) httpd_parse: read_block: received HTTP request block size = 88
D (68687) httpd_parse: continue_parsing: skip pre-parsed data of size = 5
D (68694) httpd_parse: continue_parsing: un-paused
D (68698) httpd_parse: cb_header_value: processing value = 192.168.4.1
D (68705) httpd_parse: cb_header_field: processing field = Content-Length
D (68712) httpd_parse: cb_header_value: processing value = 136
D (68718) httpd_parse: cb_header_field: processing field = Expect
D (68724) httpd_parse: cb_header_value: processing value = 100-continue
D (68731) httpd_parse: cb_header_field: processing field = Connection
D (68737) httpd_parse: cb_header_value: processing value = Keep-Alive
D (68744) httpd_parse: cb_headers_complete: bytes read     = 109
D (68750) httpd_parse: cb_headers_complete: content length = 136
D (68756) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:3 posted to loop 0x3fcb7d70
D (68756) httpd_parse: parse_block: parsed block size = 88
D (68771) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (68924) httpd_txrx: httpd_recv_with_opt: received length = 128
D (68925) httpd_parse: read_block: received HTTP request block size = 128
D (68926) httpd_txrx: httpd_unrecv: length = 128
D (68931) httpd_parse: pause_parsing: paused
D (68935) httpd_parse: cb_on_body: body begins
D (68940) httpd_parse: httpd_parse_req: parsing complete
D (68945) httpd_uri: httpd_uri: request for /ubus with type 3
D (68951) httpd_uri: httpd_find_uri_handler: [0] = /*
D (68956) httpd_uri: httpd_find_uri_handler: [1] = /upload/*
D (68962) httpd_uri: httpd_find_uri_handler: [2] = /delete/*
W (68968) httpd_uri: httpd_uri: Method '3' not allowed for URI '/ubus'
W (68975) httpd_txrx: httpd_resp_send_err: 405 Method Not Allowed - Specified method is invalid for this resource
D (68986) httpd_txrx: httpd_send_all: sent = 78
D (68991) httpd_txrx: httpd_send_all: sent = 2
D (68995) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:4 posted to loop 0x3fcb7d70
D (68995) httpd_txrx: httpd_send_all: sent = 45
D (69010) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:6 posted to loop 0x3fcb7d70
D (69010) httpd_sess: httpd_sess_delete: fd = 58
D (69020) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:0 posted to loop 0x3fcb7d70
D (69025) httpd_sess: httpd_sess_delete: active sockets: 0
D (69034) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:7 posted to loop 0x3fcb7d70
D (69040) httpd: httpd_server: doing select maxfd+1 = 56
I (69604) main: Core id: 0, prio: 1,  free heap: 8303152 bytes., minimum free heap: 8291040 bytes., minimum free stack: 1288 bytes.
VTC in safe state: SelectPreferredVT check for CF 1400 - Time: 00070327 (00063574) Boottime:  7 VTs:  0
D (70508) httpd: httpd_server: processing listen socket 54
D (70509) httpd: httpd_accept_conn: newfd = 58
D (70509) httpd_sess: httpd_sess_new: fd = 58
D (70512) httpd_sess: httpd_sess_new: active sockets: 1
D (70517) httpd: httpd_accept_conn: complete
D (70521) httpd: httpd_server: doing select maxfd+1 = 59
D (70521) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:2 posted to loop 0x3fcb7d70
D (70527) httpd: httpd_process_session: processing socket 58
D (70542) httpd_sess: httpd_sess_process: httpd_req_new
D (70548) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (70554) httpd_txrx: httpd_recv_with_opt: received length = 128
D (70560) httpd_parse: read_block: received HTTP request block size = 128
D (70567) httpd_parse: cb_url: message begin
D (70571) httpd_parse: cb_url: processing url = /
D (70576) httpd_parse: verify_url: received URI = /
D (70581) httpd_parse: cb_header_field: headers begin
D (70586) httpd_txrx: httpd_unrecv: length = 112
D (70591) httpd_parse: pause_parsing: paused
D (70595) httpd_parse: cb_header_field: processing field = Host
D (70601) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (70607) httpd_txrx: httpd_recv_with_opt: pending length = 112
D (70613) httpd_parse: read_block: received HTTP request block size = 112
D (70620) httpd_parse: continue_parsing: skip pre-parsed data of size = 5
D (70627) httpd_parse: continue_parsing: un-paused
D (70632) httpd_parse: cb_header_value: processing value = 192.168.4.1
D (70638) httpd_parse: cb_header_field: processing field = Connection
D (70645) httpd_parse: cb_header_value: processing value = keep-alive
D (70651) httpd_parse: cb_header_field: processing field = Cache-Control
D (70658) httpd_parse: cb_header_value: processing value = max-age=0
D (70665) httpd_parse: cb_header_field: processing field = Upgrade-Insecure-Requests
D (70672) httpd_parse: cb_header_value: processing value = 1
D (70678) httpd_parse: cb_header_field: processing field = User-Agent
D (70685) httpd_parse: cb_header_value: processing value = M
D (70690) httpd_parse: parse_block: parsed block size = 112
D (70696) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (70702) httpd_txrx: httpd_recv_with_opt: received length = 128
D (70708) httpd_parse: read_block: received HTTP request block size = 128
D (70715) httpd_parse: cb_header_value: processing value = ozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/117.0.0.0 Safari/537.36
D (70730) httpd_parse: cb_header_field: processing field = Accept
D (70736) httpd_parse: cb_header_value: processing value = text/htm
D (70743) httpd_parse: parse_block: parsed block size = 240
D (70748) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (70755) httpd_txrx: httpd_recv_with_opt: received length = 128
D (70761) httpd_parse: read_block: received HTTP request block size = 128
D (70767) httpd_parse: cb_header_value: processing value = l,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7
D (70784) httpd_parse: parse_block: parsed block size = 368
D (70790) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (70796) httpd_txrx: httpd_recv_with_opt: received length = 128
D (70802) httpd_parse: read_block: received HTTP request block size = 128
D (70809) httpd_parse: cb_header_field: processing field = Referer
D (70815) httpd_parse: cb_header_value: processing value = http://192.168.4.1/
D (70822) httpd_parse: cb_header_field: processing field = Accept-Encoding
D (70829) httpd_parse: cb_header_value: processing value = gzip, deflate
D (70836) httpd_parse: cb_header_field: processing field = Accept-Language
D (70843) httpd_parse: cb_header_value: processing value = de,de-DE;q=0.9,en-US;q=0.8,en;q=0.7,zh-TW;q=0.6,
D (70853) httpd_parse: parse_block: parsed block size = 496
D (70859) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (70865) httpd_txrx: httpd_recv_with_opt: received length = 12
D (70871) httpd_parse: read_block: received HTTP request block size = 12
D (70877) httpd_parse: cb_header_value: processing value = zh;q=0.5
D (70884) httpd_parse: cb_headers_complete: bytes read     = 526
D (70890) httpd_parse: cb_headers_complete: content length = 0
D (70896) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:3 posted to loop 0x3fcb7d70
D (70896) httpd_parse: pause_parsing: paused
D (70910) httpd_parse: cb_no_body: message complete
D (70915) httpd_parse: httpd_parse_req: parsing complete
D (70920) httpd_uri: httpd_uri: request for / with type 1
D (70926) httpd_uri: httpd_find_uri_handler: [0] = /*
D (70931) httpd_txrx: httpd_send_all: sent = 70
D (70936) httpd_txrx: httpd_send_all: sent = 2
D (70940) httpd_txrx: httpd_send_all: sent = 4
D (70945) httpd_txrx: httpd_send_all: sent = 27
D (70950) httpd_txrx: httpd_send_all: sent = 2
D (70954) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:6 posted to loop 0x3fcb7d70
D (70954) httpd_txrx: httpd_send_all: sent = 5
D (70969) httpd_txrx: httpd_send_all: sent = 2861
D (70973) httpd_txrx: httpd_send_all: sent = 2
D (70978) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:6 posted to loop 0x3fcb7d70
D (70978) httpd_txrx: httpd_send_all: sent = 4
D (70992) httpd_txrx: httpd_send_all: sent = 209
D (70997) httpd_txrx: httpd_send_all: sent = 2
D (71001) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:6 posted to loop 0x3fcb7d70
D (71024) httpd_txrx: httpd_send_all: sent = 4
D (71025) httpd_txrx: httpd_send_all: sent = 16
D (71025) httpd_txrx: httpd_send_all: sent = 2
D (71027) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:6 posted to loop 0x3fcb7d70
D (71027) httpd_txrx: httpd_send_all: sent = 3
D (71041) httpd_txrx: httpd_send_all: sent = 14
D (71046) httpd_txrx: httpd_send_all: sent = 2
D (71051) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:6 posted to loop 0x3fcb7d70
D (71051) httpd_txrx: httpd_send_all: sent = 3
D (71065) httpd_txrx: httpd_send_all: sent = 2
D (71070) httpd_sess: httpd_sess_process: httpd_req_delete
D (71070) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:6 posted to loop 0x3fcb7d70
D (71075) httpd_sess: httpd_sess_process: success
D (71090) httpd: httpd_server: processing listen socket 54
D (71096) httpd: httpd_accept_conn: newfd = 59
D (71100) httpd_sess: httpd_sess_new: fd = 59
D (71104) httpd_sess: httpd_sess_new: active sockets: 2
D (71110) httpd: httpd_accept_conn: complete
D (71114) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:2 posted to loop 0x3fcb7d70
D (71114) httpd: httpd_server: doing select maxfd+1 = 60
D (71130) httpd: httpd_process_session: processing socket 58
D (71135) httpd_sess: httpd_sess_process: httpd_req_new
D (71140) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (71147) httpd_txrx: httpd_recv_with_opt: received length = 128
D (71153) httpd_parse: read_block: received HTTP request block size = 128
D (71160) httpd_parse: cb_url: message begin
D (71164) httpd_parse: cb_url: processing url = /favicon.ico
D (71170) httpd_parse: verify_url: received URI = /favicon.ico
D (71175) httpd_parse: cb_header_field: headers begin
D (71181) httpd_txrx: httpd_unrecv: length = 101
D (71185) httpd_parse: pause_parsing: paused
D (71190) httpd_parse: cb_header_field: processing field = Host
D (71196) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (71202) httpd_txrx: httpd_recv_with_opt: pending length = 101
D (71208) httpd_parse: read_block: received HTTP request block size = 101
D (71215) httpd_parse: continue_parsing: skip pre-parsed data of size = 5
D (71221) httpd_parse: continue_parsing: un-paused
D (71226) httpd_parse: cb_header_value: processing value = 192.168.4.1
D (71233) httpd_parse: cb_header_field: processing field = Connection
D (71239) httpd_parse: cb_header_value: processing value = keep-alive
D (71246) httpd_parse: cb_header_field: processing field = User-Agent
D (71252) httpd_parse: cb_header_value: processing value = Mozilla/5.0 (Windows NT 10.0; Win64; x64) Appl
D (71262) httpd_parse: parse_block: parsed block size = 101
D (71268) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (71274) httpd_txrx: httpd_recv_with_opt: received length = 128
D (71280) httpd_parse: read_block: received HTTP request block size = 128
D (71287) httpd_parse: cb_header_value: processing value = eWebKit/537.36 (KHTML, like Gecko) Chrome/117.0.0.0 Safari/537.36
D (71298) httpd_parse: cb_header_field: processing field = Accept
D (71304) httpd_parse: cb_header_value: processing value = image/avif,image/webp,image/apng,image/svg+xml,image/
D (71315) httpd_parse: parse_block: parsed block size = 229
D (71320) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (71326) httpd_txrx: httpd_recv_with_opt: received length = 128
D (71332) httpd_parse: read_block: received HTTP request block size = 128
D (71339) httpd_parse: cb_header_value: processing value = *,*/*;q=0.8
D (71346) httpd_parse: cb_header_field: processing field = Referer
D (71352) httpd_parse: cb_header_value: processing value = http://192.168.4.1/
D (71359) httpd_parse: cb_header_field: processing field = Accept-Encoding
D (71366) httpd_parse: cb_header_value: processing value = gzip, deflate
D (71373) httpd_parse: cb_header_field: processing field = Accept-Language
D (71380) httpd_parse: cb_header_value: processing value = de,de-DE;q=0.9,en-US;q=0.8,en;q=0.7,
D (71389) httpd_parse: parse_block: parsed block size = 357
D (71394) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (71401) httpd_txrx: httpd_recv_with_opt: received length = 24
D (71407) httpd_parse: read_block: received HTTP request block size = 24
D (71413) httpd_parse: cb_header_value: processing value = zh-TW;q=0.6,zh;q=0.5
D (71421) httpd_parse: cb_headers_complete: bytes read     = 411
D (71427) httpd_parse: cb_headers_complete: content length = 0
D (71433) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:3 posted to loop 0x3fcb7d70
D (71433) httpd_parse: pause_parsing: paused
D (71447) httpd_parse: cb_no_body: message complete
D (71452) httpd_parse: httpd_parse_req: parsing complete
D (71457) httpd_uri: httpd_uri: request for /favicon.ico with type 1
D (71464) httpd_uri: httpd_find_uri_handler: [0] = /*
D (71492) httpd_txrx: httpd_send_all: sent = 67
D (71492) httpd_txrx: httpd_send_all: sent = 2
D (71492) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:4 posted to loop 0x3fcb7d70
D (71494) httpd_txrx: httpd_send_all: sent = 6429
D (71504) httpd_sess: httpd_sess_process: httpd_req_delete
D (71505) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:6 posted to loop 0x3fcb7d70
D (71510) httpd_sess: httpd_sess_process: success
D (71525) httpd: httpd_server: doing select maxfd+1 = 60
D (71531) httpd: httpd_process_session: processing socket 58
D (71536) httpd_sess: httpd_sess_process: httpd_req_new
D (71541) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (71548) httpd_txrx: httpd_recv_with_opt: received length = 0
D (71553) httpd_parse: read_block: connection closed
D (71558) httpd_sess: httpd_sess_delete: fd = 58
D (71563) httpd_sess: httpd_sess_delete: active sockets: 1
D (71563) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:7 posted to loop 0x3fcb7d70
D (71569) httpd: httpd_process_session: processing socket 59
D (71584) httpd_sess: httpd_sess_process: httpd_req_new
D (71590) httpd_txrx: httpd_recv_with_opt: requested length = 128
D (71596) httpd_txrx: httpd_recv_with_opt: received length = 0
D (71602) httpd_parse: read_block: connection closed
D (71607) httpd_sess: httpd_sess_delete: fd = 59
D (71612) httpd_sess: httpd_sess_delete: active sockets: 0
D (71612) event: no handlers have been registered for event ESP_HTTP_SERVER_EVENT:7 posted to loop 0x3fcb7d70
D (71617) httpd: httpd_server: doing select maxfd+1 = 56
VTC in safe state: SelectPreferredVT check for CF 1400 - Time: 00077089 (00070327) Boottime:  7 VTs:  0
I (79607) main: Core id: 0, prio: 1,  free heap: 8303152 bytes., minimum free heap: 8291040 bytes., minimum free stack: 1288 bytes.
VTC in safe state: SelectPreferredVT check for CF 1400 - Time: 00083843 (00077089) Boottime:  7 VTs:  0

@xuhongv
Copy link

xuhongv commented Nov 27, 2023

@franz-ms-muc

image

image

how can i fix it ?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Resolution: Done Issue is done internally Status: Done Issue is done internally
Projects
None yet
Development

No branches or pull requests

5 participants