SoftAP mode stuck receiving UDP packets

Tip / Sign in to post questions, reply, level up, and achieve exciting badges. Know more

cross mob
Anonymous
Not applicable

Hi,

Using Wiced SDK 4.0, I am having some issues with SoftAP Mode. This problem also happens with 3.5.x.

I am setting up a SoftAP, and then opening up a UDP socket. I'm then registering a callback function using wiced_udp_register_callbacks to process any received UDP packets (essentially just print out a counter).

I am connecting to the SoftAP from 4 different linux clients and sending UDP packets to the SoftAP. It works for 5 or so minutes, but then something happens and the WICED stack hangs and does not recover without a reset.

Any ideas?

Here is the code I am using. I've been messing with it all day, trying different things, so it's a hacked together mess at this point. Essentially it just waits for udp packets to arrive, prints info from the packet as well as where the packet came from, then echoes the packet back.

Notes:

  • The system is more stable if I send packets less often. Right now I am sending a 16 byte packet every 5 ms. After about a minute, the system chokes up and the network goes down. I lose my connection and can no longer transmit or receive (tx fails saying it can't allocate space for a packet).
  • Before the system goes down, it's dropping a bunch of packets, like it can't keep up
  • If the system can't keep up, there's no reason it should hang up. It should just throw away packets if the queue is full.
  • I've tried disabing the watchdog, with the idea that it's not being pet often enough. Problem persists.

#include "wiced.h"

#include "resources.h"

/******************************************************

*                      Macros

******************************************************/

/******************************************************

*                    Constants

******************************************************/

#define MAX_SOFT_AP_CLIENTS  (5)

/******************************************************

*                   Enumerations

******************************************************/

/******************************************************

*                 Type Definitions

******************************************************/

/******************************************************

*                    Structures

******************************************************/

typedef struct

{

    int         count;

    wiced_mac_t mac_list[MAX_SOFT_AP_CLIENTS];

} client_info_t;

/******************************************************

*               Static Function Declarations

******************************************************/

/******************************************************

*               Variable Definitions

******************************************************/

static const wiced_ip_setting_t ap_ip_settings =

{

    INITIALISER_IPV4_ADDRESS( .ip_address, MAKE_IPV4_ADDRESS( 192,168,  0,  1 ) ),

    INITIALISER_IPV4_ADDRESS( .netmask,    MAKE_IPV4_ADDRESS( 255,255,255,  0 ) ),

    INITIALISER_IPV4_ADDRESS( .gateway,    MAKE_IPV4_ADDRESS( 192,168,  0,  1 ) ),

};

static wiced_timed_event_t process_udp_rx_event;

static wiced_timed_event_t process_udp_tx_event;

static wiced_udp_socket_t  udp_socket;

static uint32_t tx_count = 1;

static uint32_t numClients = 0;

typedef struct rx_stats

{

  wiced_ip_address_t src_ip;

  uint32_t rx_count;

  uint32_t rx_count_last_second;

  uint32_t rx_count_last_second_latched;

  wiced_time_t lastReportTime;

}rx_stats;

#define MAX_CLIENTS 8

static rx_stats rxStats[MAX_CLIENTS];

void initRxStats()

{

  for( int i = 0; i < MAX_CLIENTS; i++ )

  {

  memset( &rxStats, 0, sizeof(rx_stats) );

  }

}

int getIpIndex( wiced_ip_address_t ip )

{

  for( int i = 0; i < MAX_CLIENTS; i++ )

  {

  if( memcmp( &rxStats.src_ip, &ip, sizeof(wiced_ip_address_t)) == 0 )

  {

  return i;

  }

  }

  return -1;

}

int addIp( wiced_ip_address_t ip )

{

  memcpy( &rxStats[numClients].src_ip, &ip, sizeof(wiced_ip_address_t) );

  return numClients++;

}

static wiced_result_t send_udp_response (char* buffer, uint16_t buffer_length, wiced_ip_address_t ip_addr, uint32_t port)

{

    wiced_packet_t*          packet;

    char*                    tx_data;

    uint16_t                 available_data_length;

    const wiced_ip_address_t INITIALISER_IPV4_ADDRESS( target_ip_addr, GET_IPV4_ADDRESS(ip_addr) );

    /* Create the UDP packet. Memory for the TX data is automatically allocated */

    if ( wiced_packet_create_udp( &udp_socket, buffer_length, &packet, (uint8_t**) &tx_data, &available_data_length ) != WICED_SUCCESS )

    {

    printf("Available data length: %d\n", available_data_length);

        WPRINT_APP_INFO( ("UDP tx packet creation failed\n") );

        return WICED_ERROR;

    }

    printf("Available data length: %d\n", available_data_length);

    /* Copy buffer into tx_data which is located inside the UDP packet */

    memcpy( tx_data, buffer, buffer_length + 1 );

    /* Set the end of the data portion of the packet */

    wiced_packet_set_data_end( packet, (uint8_t*) tx_data + buffer_length );

    /* Send the UDP packet */

    if ( wiced_udp_send( &udp_socket, &target_ip_addr, port, packet ) != WICED_SUCCESS )

    {

        WPRINT_APP_INFO( ("UDP packet send failed\n") );

        /* Delete packet, since the send failed */

        wiced_packet_delete( packet );

    }

    /*

     * NOTE : It is not necessary to delete the packet created above, the packet

     *        will be automatically deleted *AFTER* it has been successfully sent

     */

    return WICED_SUCCESS;

}

void process_received_udp_packet( wiced_thread_arg_t arg )

{

  char*                     rx_data;

  static uint16_t           rx_data_length;

  uint16_t                  available_data_length;

  static wiced_ip_address_t udp_src_ip_addr;

  static uint16_t           udp_src_port;

  while(1)

  {

  wiced_packet_t*           packet;

  /* Wait for UDP packet */

  wiced_result_t result = wiced_udp_receive( &udp_socket, &packet, WICED_NEVER_TIMEOUT );

  if ( ( result == WICED_ERROR ) || ( result == WICED_TIMEOUT ) )

  {

  continue;

  }

  wiced_time_t time;

  wiced_time_get_time(&time);

  //printf("(%d)RX Packet\n", time);

  /* Get info about the received UDP packet */

  wiced_udp_packet_get_info( packet, &udp_src_ip_addr, &udp_src_port );

  int rxStatsIndex = getIpIndex(udp_src_ip_addr);

  if( rxStatsIndex < 0 )

  {

  rxStatsIndex = addIp(udp_src_ip_addr);

  }

  /* Extract the received data from the UDP packet */

  wiced_packet_get_data( packet, 0, (uint8_t**) &rx_data, &rx_data_length, &available_data_length );

  wiced_time_t currentTime = 0;

  wiced_time_get_time(&currentTime);

  rxStats[rxStatsIndex].rx_count_last_second++;

  rxStats[rxStatsIndex].rx_count++;

  uint32_t sentCount = 0;

  memcpy( &sentCount, rx_data, sizeof(sentCount) );

  if( currentTime - rxStats[rxStatsIndex].lastReportTime > 1000 )

  {

  WPRINT_APP_INFO ( ("(%d)UDP Rx(%u.%u.%u.%u): \"%lu\" nRx: %d (%d) nRx Last Sec: %d\n",

  time,

  (unsigned char) ( ( udp_src_ip_addr.ip.v4 >> 24 ) & 0xff ),

  (unsigned char) ( ( udp_src_ip_addr.ip.v4 >> 16 ) & 0xff ),

  (unsigned char) ( ( udp_src_ip_addr.ip.v4 >> 8 ) & 0xff ),

  (unsigned char) ( ( udp_src_ip_addr.ip.v4 >> 0 ) & 0xff ),

  sentCount, rxStats[rxStatsIndex].rx_count,

  (rxStats[rxStatsIndex].rx_count - sentCount),rxStats[rxStatsIndex].rx_count_last_second_latched));

  rxStats[rxStatsIndex].rx_count_last_second_latched = rxStats[rxStatsIndex].rx_count_last_second;

  rxStats[rxStatsIndex].rx_count_last_second = 0;

  rxStats[rxStatsIndex].lastReportTime = currentTime;

  }

  wiced_packet_delete( packet );

  uint32_t respPort = 0;

  memcpy( &respPort, &rx_data[4], 4 );

  /* Echo the received data to the sender */

  send_udp_response( rx_data, rx_data_length, udp_src_ip_addr, respPort );

  }

}

static int numConnections = 0;

wiced_thread_t rxThread;

/******************************************************

*               Function Definitions

******************************************************/

void application_start(void)

{

    int32_t         rssi = 0;

    int             client_number = 0;

    wiced_result_t  result;

    client_info_t   client_info;

    client_info.count = MAX_SOFT_AP_CLIENTS;

    /* Initialise Wiced system */

    wiced_init();

    /* Bring up the softAP interface  */

    wiced_network_up( WICED_AP_INTERFACE, WICED_USE_INTERNAL_DHCP_SERVER, &ap_ip_settings );

    /* Create UDP socket */

    if (wiced_udp_create_socket(&udp_socket, 1234, WICED_AP_INTERFACE) != WICED_SUCCESS)

    {

        WPRINT_APP_INFO( ("UDP socket creation failed\n") );

    }

    wiced_rtos_create_thread( &rxThread, WICED_NETWORK_WORKER_PRIORITY, "rx thread", &process_received_udp_packet, 8000, NULL );

    //wiced_udp_register_callbacks( &udp_socket, &process_received_udp_packet, NULL );

    int loopCount = 0;

    while ( 1 )

    {

    if( !wiced_network_is_up( WICED_AP_INTERFACE ) )

    {

    printf("Network is down\n");

    }

        printf("Still alive!\n");

        loopCount++;

        /* Sleep for a second and do it again */

        //WPRINT_APP_INFO( ("Waiting for an update...\r\n\r\n") );

        wiced_rtos_delay_milliseconds( 1000 );

    }

}

Message was edited by: Nick Crast Adding code sample

0 Likes
13 Replies
Anonymous
Not applicable

Bump.

Also want to note that the problem exists with both ThreadX/NetX and FreeRTOS/LwIP.

0 Likes

I'd like to see an answer to this question too.  We haven't created simplified error-reproduction steps yet, but anecdotally we've seen general instability issues caused by putting the system under higher load.

nrcrast​ -- have you tried running this test case with the JTAG debugger attached to your project?  I expect its hitting an assert somewhere that is causing the program to hang.

0 Likes
Anonymous
Not applicable

Just  ran it with the debugger attached. Didn't hit any assert or anything. However, when compiling for debug, the system is even less stable. It only processes data for a second or two before the network stops working.

0 Likes

And if you pause with the debugger attached once it's into that state does everything look normal?  I presume your rxThread is just stalled waiting on the next UDP packet which never arrives(?)

One thing I'm seeing which may be an issue (though I don't think it could lead to the problem you're seeing) -- you're deleting the UDP packet you received prior to using its payload to generate the echo content.

Anonymous
Not applicable

That's a good catch. I was seeing the problem before I even had the echo code in, though.

I'm thinking it might be an optimization issue. I went in and forced optimization to -O1 instead of -0s, and so far it has been running at 465 packets of 128B every second for about 5 minutes straight. I will let it go for a few hours and see what happens. After this test, I'll check the rxthread to make sure it's still running in the bad case, but I presume it's just sitting there waiting for a packet to arrive.

Update: Spoke too soon. Crashed and burned with -O1.

0 Likes
Anonymous
Not applicable

The traces are identical on startup vs when the system is in a 'bad state'.

last_built.elf

Thread [2] 536922976 (IDLE :  : Running) (Suspended : Signal : SIGINT:Interrupt)

  stop_mode_power_down_hook() at platform_mcu_powersave.c:384 0x800ff54

  platform_power_down_hook() at platform_mcu_powersave.c:300 0x800fe8a

  prvIdleTask() at tasks.c:2,904 0x800d88c

  pxPortInitialiseStack() at port.c:227 0x800cbb4

  Thread [3] 536916376 (system monitor) (Suspended : Container)

  vPortYield() at port.c:386 0x800ccd8

  xQueueGenericReceive() at queue.c:1,574 0x800ebec

  host_rtos_get_semaphore() at wwd_rtos.c:163 0x800f00e

  wiced_rtos_get_semaphore() at wiced_rtos_common.c:143 0x8015798

  system_monitor_thread_main() at system_monitor.c:114 0x8014952

  pxPortInitialiseStack() at port.c:227 0x800cbb4

Thread [4] 536922624 (app_thread) (Suspended : Container)

  vPortYield() at port.c:386 0x800ccd8

  vTaskDelay() at tasks.c:1,004 0x800d0ee

  host_rtos_delay_milliseconds() at wwd_rtos.c:274 0x800f0e4

  wiced_rtos_delay_milliseconds() at wiced_rtos_common.c:112 0x8015742

  application_start() at ap_clients_rssi.c:290 0x80148ba

  application_thread_main() at wiced_rtos.c:138 0x800f29c

  pxPortInitialiseStack() at port.c:227 0x800cbb4

  Thread [5] 536934896 (tcpip_thread) (Suspended : Container)

  vPortYield() at port.c:386 0x800ccd8

  xQueueGenericReceive() at queue.c:1,574 0x800ebec

  sys_arch_mbox_fetch() at sys_arch.c:152 0x802b2ca

  sys_timeouts_mbox_fetch() at timers.c:519 0x802334c

  tcpip_thread() at tcpip.c:91 0x801f0b6

  pxPortInitialiseStack() at port.c:227 0x800cbb4

Thread [6] 536924248 (Tmr Svc) (Suspended : Container)

  vPortYield() at port.c:386 0x800ccd8

  prvProcessTimerOrBlockTask() at timers.c:516 0x800df84

  prvTimerTask() at timers.c:471 0x800df22

  pxPortInitialiseStack() at port.c:227 0x800cbb4

  Thread [7] 536955688 (rx thread) (Suspended : Container)

  vPortYield() at port.c:386 0x800ccd8

  xQueueGenericReceive() at queue.c:1,574 0x800ebec

  sys_arch_mbox_fetch() at sys_arch.c:152 0x802b2ca

  netconn_recv_data() at api_lib.c:383 0x801d982

  netconn_recv() at api_lib.c:508 0x801db6e

  wiced_udp_receive() at tcpip.c:902 0x8016454

  process_received_udp_packet() at ap_clients_rssi.c:182 0x801461e

  pxPortInitialiseStack() at port.c:227 0x800cbb4

  Thread [9] 536937608 (WWD) (Suspended : Container)

  vPortYield() at port.c:386 0x800ccd8

  xQueueGenericReceive() at queue.c:1,574 0x800ebec

  host_rtos_get_semaphore() at wwd_rtos.c:163 0x800f00e

  wwd_wait_for_wlan_event() at wwd_thread_internal.c:58 0x801b3da

  wwd_thread_func() at wwd_thread.c:324 0x801b33c

  pxPortInitialiseStack() at port.c:227 0x800cbb4

0 Likes
Anonymous
Not applicable

Getting closer. Enabling stats in LwIP, I'm seeing this after data stops being received:

MEM PBUF_POOL_RX

        avail: 10

        used: 0

        max: 10

        err: 6

SYS

        sem.used:  0

        sem.max:   0

        sem.err:   0

        mutex.used: 0

        mutex.max:  0

        mutex.err:  0

        mbox.used:  0

        mbox.max:   0

        mbox.err:   104

        Still alive!

Looks like there's an RX memory allocation error, which is OK if I'm sending data too fast. But the question is why does it not recover?

0 Likes
Anonymous
Not applicable

Hi.

If I remember ok, bug in wiced_packet_delete. I will check  self code later.

P.S.

Incorrectly using wiced_packet_get_data return params

0 Likes
Anonymous
Not applicable

Just a bump to figure out if you found a bug in wiced_packet_delete?

0 Likes
Anonymous
Not applicable

Sorry, not in wiced_packet_delete problem. Errors was in other place in wiced_tcp_connect and   wiced_tcp_delete_socket, but not in  wiced_packet_delete.

But one note.

    /* Create the UDP packet. Memory for the TX data is automatically allocated */

    if ( wiced_packet_create_udp( &udp_socket, buffer_length, &packet, (uint8_t**) &tx_data, &available_data_length ) != WICED_SUCCESS )

    {

    printf("Available data length: %d\n", available_data_length);

        WPRINT_APP_INFO( ("UDP tx packet creation failed\n") );

        return WICED_ERROR;

    }

    printf("Available data length: %d\n", available_data_length);

    /* Copy buffer into tx_data which is located inside the UDP packet */

    memcpy( tx_data, buffer, buffer_length + 1 );

wiced_packet_create_udp   buffer size buffer_length,  but memcpy  copy  (buffer_length + 1 ) size.

0 Likes
Anonymous
Not applicable

More clues. I have found that in the error case, I just stop receiving the SDIO interrupt altogether. Not sure why that is.

0 Likes

Good find nrcrast​.  Can someone from Cypress please try reproducing this test?

Plausibly the error is occurring inside the radio firmware, or somewhere in the WWD driver layer (/SDIO interface).

0 Likes
Anonymous
Not applicable

I have attached sources and reproduction instructions here:

System hanging after receiving UDP packets

Sorry for the multiple threads.

-Nick

0 Likes