repeated socket()/close() runs out of sockets

[rleinfellner]

Environment

• Development Kit: [ESP32-DevKitC]
• Kit version (DevKitC): [v2]
• Core (if using chip or module): [|ESP-WROOM32]
• IDF version (git rev-parse --short HEAD to get the commit id.): 405b198
• Development Env: [Eclipse]
• Operating System: [Windows]
• Power Supply: [USB]

Problem Description

//Detailed problem description goes here.
http_request example, issue with repeated socket()/close()
After a number of cycles, no more sockets are available
It looks like close() is not marking the socket as reuseable

Expected Behavior

you should be able to open()/close(0 sockets as many time as you like

Actual Behavior

After 10 socket()/close() cycles the system runs out of sockets

Steps to reproduce

Compile and run standard http-request example
After 10 cycles the system runs out of sockets

Debug log, note the code has been modified to print the socket handle, this starts at 4096 and increments to 4105 before no more sockets are availiable

Test = 100
I (138849) example: ... done reading from socket. Last read return=-1 errno=11

I (138849) example: 10...
I (139849) example: 9...
I (140849) example: 8...
I (141849) example: 7...
I (142849) example: 6...
I (143849) example: 5...
I (144849) example: 4...
I (145849) example: 3...
I (146849) example: 2...
I (147849) example: 1...
I (148849) example: 0...
I (149849) example: Starting again!
I (149849) example: Connected to AP
I (149849) example: DNS lookup succeeded. IP=192.64.118.69
I (149849) example: ... allocated socket 4105
I (150049) example: ... connected
I (150049) example: ... socket send success
I (150049) example: ... set socket receiving timeout success
HTTP/1.1 200 OK
Date: Sun, 16 Sep 2018 11:23:44 GMT
Server: Apache
Last-Modified: Sun, 16 Sep 2018 10:46:31 GMT
Accept-Ranges: bytes
Content-Length: 11
Keep-Alive: timeout=3, max=200
Connection: close

Test = 100
I (155259) example: ... done reading from socket. Last read return=-1 errno=11

I (155259) example: 10...
I (156259) example: 9...
I (157259) example: 8...
I (158259) example: 7...
I (159259) example: 6...
I (160259) example: 5...
I (161259) example: 4...
I (162259) example: 3...
I (163259) example: 2...
I (164259) example: 1...
I (165259) example: 0...
I (166259) example: Starting again!
I (166259) example: Connected to AP
I (166259) example: DNS lookup succeeded. IP=192.64.118.69
E (166259) example: ... Failed to allocate socket.

[rleinfellner]

Also checked LWIP_SO_REUSE is set so it should not be waiting

[dobairoland]

I think this is the same problem as #2403.

[david-cermak]

Hi Richard,

Running the http-request example with default configuration and specified IDF version caused no socket exhaustion.
I was able to recreate the problem you describe, only when switched the socket into non-blocking mode fcntl(s, F_SETFL, O_NONBLOCK);.
In that case, as dobairoland suggests, the issue is be caused by the same bug as in #2403.
LWIP team has prepared a critical bugfix, which should solve the issue (expecting that's the same one from the output ... errno=11 of your http-request example).

Could you please confirm that return value of close(s) is always 0 in your setup?

ESP_LOGI(TAG, "... done reading from socket. Last read return=%d errno=%d\r\n", r, errno);
r = close(s);
ESP_LOGI(TAG, "... Last close socket return value=%d\r\n", r);

Thank you,
David

[rleinfellner]

I have just gone back to my project to check on the close() return and am unable to build it anymore as make makeconfig fails with make: *** No rule to make target 'makeconfig'. Stop.
No idea whats going on, will try again later

[rleinfellner]

OK, added code to print return value of close
It always
I (138750) example: ... done reading from socket. Last read return=-1 errno=11

I (138750) example: ... Last close socket return value=0

After Socket Handle 4105 it fails
NB: Other than more debug and adding my SID this is the vanilla example (ie I did not change blocking)

About to try the proposed fix

[rleinfellner]

Commit ID:eea49d250 seems to fix the issue with the sockets not being freed on close.
They start at 54 then go up to 63, before looping back to 54.

[zhangyanjiaoesp]

@rleinfellner This probelm has been solved in the commit：a5533a0. You can close this issue.