PYBv10:In multithreading, when I use different functions for udp socket, I find that performance is different

[Li-Weiwei]

In #3302, I found that when I call the recvfrom function of the udp socket, I made the micropython no longer running. Now, it is fixed by cc7fece309b0ce6d361cade8690b6c3a162d7378, like this:

STATIC mp_uint_t wiznet5k_socket_recvfrom(mod_network_socket_obj_t *socket, byte *buf, mp_uint_t len, byte *ip, mp_uint_t *port, int *_errno) {
    uint16_t port2;
    MP_THREAD_GIL_EXIT();     // fixed here
    mp_int_t ret = WIZCHIP_EXPORT(recvfrom)(socket->u_param.fileno, buf, len, ip, &port2);
    MP_THREAD_GIL_ENTER();    // fixed here
    *port = port2;
    if (ret < 0) {
        wiznet5k_socket_close(socket);
        *_errno = -ret;
        return -1;
    }
    return ret;
}

I found the message of cc7fece309b0ce6d361cade8690b6c3a162d7378 said that "accept already releases the GIL because it calls mp_hal_delay_ms() within its busy-wait loop." So I modified the code like this below:

diff --git a/drivers/wiznet5k/ethernet/socket.c b/drivers/wiznet5k/ethernet/socket.c
index 129473a..9ec3534 100644
--- a/drivers/wiznet5k/ethernet/socket.c
+++ b/drivers/wiznet5k/ethernet/socket.c
@@ -55,6 +55,8 @@
 #include "socket.h"

 extern void HAL_Delay(uint32_t);
+typedef unsigned int mp_uint_t;
+extern void mp_hal_delay_ms(mp_uint_t);

 #define SOCK_ANY_PORT_NUM  0xC000;

@@ -485,6 +487,7 @@ int32_t WIZCHIP_EXPORT(recvfrom)(uint8_t sn, uint8_t * buf, uint16_t len, uint8_
          pack_len = getSn_RX_RSR(sn);
          if(getSn_SR(sn) == SOCK_CLOSED) return SOCKERR_SOCKCLOSED;
          if( (sock_io_mode & (1<<sn)) && (pack_len == 0) ) return SOCK_BUSY;
+         mp_hal_delay_ms(1);
          if(pack_len != 0) break;
       };
    }
diff --git a/ports/stm32/modnwwiznet5k.c b/ports/stm32/modnwwiznet5k.c
index 2d5a8d5..c85d974 100644
--- a/ports/stm32/modnwwiznet5k.c
+++ b/ports/stm32/modnwwiznet5k.c
@@ -277,9 +277,9 @@ STATIC mp_uint_t wiznet5k_socket_sendto(mod_network_socket_obj_t *socket, const

 STATIC mp_uint_t wiznet5k_socket_recvfrom(mod_network_socket_obj_t *socket, byte *buf, mp_uint_t len, byte
     uint16_t port2;
-    MP_THREAD_GIL_EXIT();
+    //MP_THREAD_GIL_EXIT();
     mp_int_t ret = WIZCHIP_EXPORT(recvfrom)(socket->u_param.fileno, buf, len, ip, &port2);
-    MP_THREAD_GIL_ENTER();
+    //MP_THREAD_GIL_ENTER();
     *port = port2;
     if (ret < 0) {
         wiznet5k_socket_close(socket);

I find that before and after the modification, micropython performance changes greatly. I write a script to test this phenomenon:

# -*- coding: utf-8 -*-

import pyb
import network
import socket
import _thread

def work_thread():
    print_times = 0
    while True:
        busy_delay = 1000
        while busy_delay:
            busy_delay = busy_delay - 1
        print_times = print_times + 1
        print('print_times:%d' %(print_times))

def sock_thread(sock):
    while True:
        print('sock_thread')
        data, addr = sock.recvfrom(1024)

def test():
    nic = network.WIZNET5K(pyb.SPI(1), pyb.Pin.board.X5, pyb.Pin.board.X4)
    nic.ifconfig(('192.168.1.2', '255.255.255.0', '192.168.1.1', '192.168.1.1'))
    print(nic.ifconfig())

    _thread.start_new_thread(work_thread, ())

    sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
    sock.bind(('', 1031))

    _thread.start_new_thread(sock_thread, (sock,))

    pyb.delay(24 * 60 * 60 * 1000)

Before the code is modified, print('print_times:%d' %(print_times)) runs about 9000 times in 60 seconds. But after modification, it can run about 30000 times in 60 seconds.
I do not know much about micropython, so I do not know if this is right or wrong. @dpgeorge

[dpgeorge]

Before the code is modified, print('print_times:%d' %(print_times)) runs about 9000 times in 60 seconds. But after modification, it can run about 30000 times in 60 seconds.

That sounds reasonable. Before your patch, WIZCHIP_EXPORT(recvfrom) was sitting in a busy-wait loop polling the Wiznet device. It was therefore using about 50% of the CPU, and the other 50% was used by work_thread(). After your patch, WIZCHIP_EXPORT(recvfrom) was yielding to the thread scheduler, telling it to schedule another waiting thread (namely work_thread()). So in your case pretty much 99% of the CPU time was spent in work_thread().

[Li-Weiwei]

In fact, once the socket has been added to a program without that modification, it will result in a much lower program efficiency.I'm not sure if there are other places like this.Will the problem be fixed in the future?

[dpgeorge]

Fixed by above PR.