select.ipoll can crash micropython with nonblocking sockets in an error state

[simon-budig]

Under certain conditions select.ipoll can crash.

Attached is a module that has two functions: One to set up a testbed-server and one as a testbed-client.

I've installed this on two Wemos-D1 mini pro's. On the first one I run the server (just for setting up the wifi)

MicroPython v1.9.1-8-g7213e78d on 2017-06-12; ESP module with ESP8266
Type "help()" for more information.
>>> import socktest
>>> socktest.do_server ()
#5 ets_task(4020edc0, 29, 3fff9508, 10)
opened network "esptest", IP: 192.168.4.1
listening on ('0.0.0.0', 80)

On the second one I run a client, that opens two nonblocking sockets, trying to connect to the server on the wrong port (81 instead of 80).

The sockets enter an error state due to the wrong port and the client fails to remove them from the poll object.

On the next ipoll() micropython crashes, the esp8266 resets.

MicroPython v1.9.1-8-g7213e78d on 2017-06-12; ESP module with ESP8266
Type "help()" for more information.
>>> import socktest
>>> socktest.do_client ()
#5 ets_task(4020ed88, 28, 3fff9508, 10)
connecting to "esptest"
...done
building connections to ('192.168.4.1', 81)
connect [Errno 115] EINPROGRESS
connect [Errno 115] EINPROGRESS
current sockets:
pre-poll
Event: (<socket state=1 timeout=0 incoming=0 off=0>, 4)
new connection
Event: (<socket state=-9 timeout=0 incoming=0 off=0>, 4)
new connection
send error [Errno 104] ECONNRESET
current sockets:
 - <socket state=-9 timeout=0 incoming=0 off=0>
pre-poll

 ets Jan  8 2013,rst cause:2, boot mode:(3,6)

load 0x40100000, len 32000, room 16 
tail 0
chksum 0xee
load 0x3ffe8000, len 1104, room 8 
tail 8
chksum 0xaa
load 0x3ffe8450, len 3000, room 0 
tail 8
chksum 0xc0
csum 0xc0

For some reason I can't attach the code as an attachment - sorry, I have to paste it here:

import network, time
import socket, select


def do_client (port=81):
   sta_if = network.WLAN (network.STA_IF)
   ap_if = network.WLAN (network.AP_IF)
   sta_if.active (False)
   ap_if.active (False)
   time.sleep (0.05)
   sta_if.active (True)
   sta_if.connect ("esptest", "12345678")
   print ("connecting to \"esptest\"")
   while not sta_if.isconnected ():
      time.sleep (0.05)
   print ("...done")

   p = select.poll ()
   connections = []
   addr = socket.getaddrinfo (sta_if.ifconfig ()[-1], port)[0][-1]
   print ("building connections to", addr)

   for i in range (2):
      sock = socket.socket ()
      sock.setblocking (False)
      p.register (sock, select.POLLERR | select.POLLOUT | select.POLLIN | select.POLLHUP)
      try:
         sock.connect (addr)
         print ("connect done")
      except OSError as e:
         print ("connect", e)

   while True:
      print ("current sockets:")
      for c in connections:
         print (" -", c)
      print ("pre-poll")

      for event in p.ipoll (-1):
         print ("Event:", event)
         if not event[0] in connections and event[1] & select.POLLOUT:
            print ("new connection")
            p.modify (event[0], select.POLLERR | select.POLLIN | select.POLLOUT | select.POLLHUP)
            try:
               event[0].send (" ")
               connections.append (event[0])
            except OSError as e:
               print ("send error", e)
         elif event[0] in connections and event[1] & select.POLLOUT:
            event[0].send ("some data")
            p.modify (event[0], select.POLLERR | select.POLLIN | select.POLLHUP)
         elif event[0] in connections and event[1] & select.POLLIN:
            data = event[0].read (32)
            if data:
               print ("got data", repr (data))
            else:
               print ("short read, closing connection")
               p.unregister (event[0])
               event[0].close ()
               connections.remove (event[0])
         elif event[0] in connections and event[1] & select.POLLHUP:
            print ("HUP, closing connection")
            p.unregister (event[0])
            event[0].close ()
            connections.remove (event[0])
         else:
            print ("unknown event:", event)
            p.unregister (event[0])
            event[0].close ()
            clients.remove (client)




def do_server (port=80):
   sta_if = network.WLAN (network.STA_IF)
   ap_if = network.WLAN (network.AP_IF)
   sta_if.active (False)
   ap_if.active (False)
   time.sleep (0.05)
   ap_if.active (True)
   ap_if.config (essid='esptest',
                 authmode=network.AUTH_WPA_WPA2_PSK,
                 password="12345678")
   print ("opened network \"%s\", IP: %s" % ("esptest", ap_if.ifconfig()[0]))

   p = select.poll ()

   addr = socket.getaddrinfo ('0.0.0.0', port)[0][-1]
   sock = socket.socket ()
   sock.bind (addr)
   sock.setblocking (False)
   sock.listen (1)
   p.register (sock, select.POLLIN)
   print ("listening on", addr)
   clients = []

   while True:
      for event in p.ipoll (-1):
         if event[0] == sock:
            cl, addr = sock.accept ()
            print ('connection from', addr)
            p.register (cl, select.POLLIN)
            clients.append (cl)
         elif event[0] in clients and event[1] & select.POLLIN:
            data = event[0].read (32)
            if data:
               print ("got data", repr (data))
            else:
               print ("short read, closing connection")
               p.unregister (event[0])
               event[0].close ()
               clients.remove (event[0])
         elif event[0] in clients and event[1] & select.POLLHUP:
            print ("HUP, closing connection")
            p.unregister (event[0])
            event[0].close ()
            clients.remove (event[0])
         else:
            print ("unknown event:", event)
            p.unregister (event[0])
            event[0].close ()
            clients.remove (client)

[dpgeorge]

Thanks for the report. I can't reproduce your exact error but I can find 2 related issues.

Here is a minimal test script:

try:
    import usocket as socket
except:
    import socket
try:
    import uselect as select
except:
    import select

def do_client(ip, port):
    addr = socket.getaddrinfo(ip, port)[0][-1]
    s = socket.socket()
    s.setblocking(False)
    try:
        s.connect(addr)
        print("connect done")
    except OSError as e:
        print("connect", e)

    p = select.poll()
    p.register(s, select.POLLERR | select.POLLOUT | select.POLLIN | select.POLLHUP)
    for event in p.poll(-1):
        print("event:", event)
        if event[1] & select.POLLOUT:
            print("new connection")
            try:
                s.send(b'some data')
                print('send succeeded')
            except OSError as e:
                print("send failed:", e)

do_client('<any valid IP address>', 12345)

You can run it on CPython, uPy unix and uPy esp8266. On CPython and uPy unix it has the following result:

connect [Errno 115] EINPROGRESS
event: (<_socket 3>, 29)
new connection
send failed: [Errno 111] ECONNREFUSED

This means: the connection was in progress, poll returned a POLLOUT event, but when trying to send data there is an ECONNREFUSED error (since port 12345 is invalid, but the IP address is valid).

On esp8266 it gives:

connect [Errno 115] EINPROGRESS
event: (<socket state=1 timeout=0 incoming=0 off=0>, 4)
new connection
send succeeded

So it allows to send data even though the connection is not established. The problem seems to be that lwip allows to send TCP data even if the socket is not yet connected.

The second issue (which seems more related to the original report above) is the following: take the same test script above and remove the s.setblocking(False) line. Running it on CPython and uPy unix gives:

connect [Errno 111] ECONNREFUSED
event: (<_socket 3>, 20)
new connection
send failed: 32

while on esp8266 it gives:

connect [Errno 104] ECONNRESET
Fatal exception 28(LoadProhibitedCause):
...

There are 2 issues here: lwip is returning ECONNRESET instead of ECONNREFUSED, and polling of a socket in this state leads to a crash.

[dpgeorge]

The issue with crashing when polling a closed/invalid socket is due to lwip_socket_ioctl dereferencing the null pointer socket->pcb.tcp. It's easy to add a check to guard against this, but probably that's not the right thing to do because poll should probably return something for sockets in such a state (eg POLLHUP or POLLERR).

[dpgeorge]

The issue with crashing on poll was fixed by 318f874

The other issues with wrong error codes and error behaviour still remain.

[belyalov]

Confirm, crash gone.

[varna9000]

[Edit] Turns out this error occurs only if set socket.setblocking(False). No error occurs if blocking socket are set. I'm no expert, so it might be something trivial I'm missing.

I think this issue might have been back in v1.10. Please check the output of the @dpgeorge example code:

MicroPython v1.10-8-g8b7039d7d on 2019-01-26; ESP module with ESP8266
Type help() for more information. [backend=GenericMicroPython]
%Run async_main.py
Done.
(192.168.4.2, 255.255.255.0, 192.168.4.1, 192.168.4.1)
connect [Errno 115] EINPROGRESS
event: (socket state=2 timeout=0 incoming=0 off=0, 4)
new connection
send succeeded

[dpgeorge]

@varna9000 as mentioned above, the crash is fixed but the other issues are not. It doesn't look like you are seeing a crash, so the error is not back.