Jump to content

    
Sign in to follow this  
Ruslan1

LwIP : как понять причину "netconn_accept: invalid recvmbox"

Recommended Posts

Здравствуйте!

Есть такая система:

LwIP 1.4.1, FreeRTOS, на процессоре STM32F429

Иногда возникает ошибка "netconn_accept: invalid recvmbox", генерируемая функцией netconn_recv_data(), в строке:

  LWIP_ERROR("netconn_accept: invalid recvmbox", sys_mbox_valid(&conn->recvmbox), return ERR_CONN;);

То есть указатель 'recvmbox' равен нулю.

Но при этом не вижу ошибок в логах при создания самого recvmbox или conn (во время выделения памяти).

Как такое может быть? Единственное что приходит на ум- это что идет обращение к уже закрытому соединению. Или есть еще варианты? (ну и конечно это может быть порча области памяти другой задачей, но этот вариант выходит за рамки задаваемого вопроса).

Непонятно, как можно оследить откуда это было вызвано? Там работа через callback функции. Может происходит что-то вроде: соединение уже удалено, но callback сработал и вызвал обращение к уже несуществующему указателю? Можно ли как-то отследить кто такое сделал, или хоть понять чей 'recvmbox' испорчен?  Или это при попытке закрыть уже закрытое соединение может быть?

Какие логи включить в LwIP ?

пока что включил так:

#define LWIP_DEBUG 1
#define LWIP_STATS	1
#define LWIP_STATS_DISPLAY	1
#define MEM_STATS	1
#define MEMP_STATS	1
#define SYS_STATS	1
#define SOCKETS_DEBUG                   LWIP_DBG_ON
#define MEMP_DEBUG                      LWIP_DBG_ON
#define LWIP_PLATFORM_DIAG(x)    do {printf x;} while(0)

ну и логирую периодически текущее состояние через stats_display().

К сожалению, ошибка редкая, пока не не удалось ее получить во время логирование статистики. Вот и думаю, что еще сделать чтобы:

1) увидеть причину

2) может быть спровоцировать данную проблему чтобы она повторилась на столе, и спокойно отлаживать. Например, ужать какие-то параметры конфигурации, чтобы понять что именно этого ресурса не хватает.

 

лог статистики из программы (но это без ошибки):

Quote

LINK
    xmit: 0
    recv: 0
    fw: 0
    drop: 0
    chkerr: 0
    lenerr: 0
    memerr: 0
    rterr: 0
    proterr: 0
    opterr: 0
    err: 0
    cachehit: 0

ETHARP
    xmit: 79
    recv: 31312
    fw: 0
    drop: 60
    chkerr: 0
    lenerr: 0
    memerr: 0
    rterr: 0
    proterr: 60
    opterr: 0
    err: 0
    cachehit: 7326

IP
    xmit: 7351
    recv: 6686
    fw: 0
    drop: 0
    chkerr: 0
    lenerr: 0
    memerr: 0
    rterr: 0
    proterr: 0
    opterr: 0
    err: 0
    cachehit: 0

ICMP
    xmit: 0
    recv: 0
    fw: 0
    drop: 0
    chkerr: 0
    lenerr: 0
    memerr: 0
    rterr: 0
    proterr: 0
    opterr: 0
    err: 0
    cachehit: 0

UDP
    xmit: 1091
    recv: 9083
    fw: 0
    drop: 0
    chkerr: 0
    lenerr: 0
    memerr: 0
    rterr: 0
    proterr: 0
    opterr: 0
    err: 0
    cachehit: 929

TCP
    xmit: 45754
    recv: 63139
    fw: 0
    drop: 0
    chkerr: 0
    lenerr: 0
    memerr: 0
    rterr: 0
    proterr: 0
    opterr: 0
    err: 0
    cachehit: 0

MEM HEAP
    avail: 117760
    used: 72
    max: 1176
    err: 0

MEM RAW_PCB
    avail: 4
    used: 0
    max: 0
    err: 0

MEM UDP_PCB
    avail: 12
    used: 3
    max: 3
    err: 0

MEM TCP_PCB
    avail: 35
    used: 34
    max: 35
    err: 0

MEM TCP_PCB_LISTEN
    avail: 7
    used: 1
    max: 1
    err: 0

MEM TCP_SEG
    avail: 66
    used: 0
    max: 4
    err: 0

MEM NETBUF
    avail: 10
    used: 1
    max: 3
    err: 0

MEM NETCONN
    avail: 26
    used: 2
    max: 4
    err: 0

MEM TCPIP_MSG_API
    avail: 8
    used: 0
    max: 1
    err: 0

MEM TCPIP_MSG_INPKT
    avail: 8
    used: 0
    max: 1
    err: 0

MEM SYS_TIMEOUT
    avail: 10
    used: 6
    max: 6
    err: 0

MEM NETDB
    avail: 10
    used: 0
    max: 1
    err: 0

MEM PPP_PCB
    avail: 1
    used: 0
    max: 0
    err: 0

MEM PBUF_REF/ROM
    avail: 12
    used: 0
    max: 1
    err: 0

MEM PBUF_POOL
    avail: 20
    used: 0
    max: 3
    err: 0

SYS
    sem.used:  4
    sem.max:   6
    sem.err:   0
    mutex.used: 0
    mutex.max:  0
    mutex.err:  0
    mbox.used:  3
    mbox.max:   5
    mbox.err:   0

может просто в настройках напортачил, вот они:

#define SYS_LIGHTWEIGHT_PROT    1

#define ETHARP_TRUST_IP_MAC     0
#define IP_REASSEMBLY           0
#define IP_FRAG                 0
#define ARP_QUEUEING            0
#define NO_SYS                  0
#define MEM_ALIGNMENT           4

//#define MEMP_MEM_MALLOC                 1

#define MEM_SIZE                (115*1024)

#define MEMP_SEPARATE_POOLS             1

#define MEMP_OVERFLOW_CHECK             1

#define MEMP_SANITY_CHECK               0

/* MEMP_NUM_PBUF: the number of memp struct pbufs. If the application
   sends a lot of data out of ROM (or other static memory), this
   should be set high. */
#define MEMP_NUM_PBUF           12
/* MEMP_NUM_UDP_PCB: the number of UDP protocol control blocks. One
   per active UDP "connection". */
#define MEMP_NUM_UDP_PCB        12
/* MEMP_NUM_TCP_PCB: the number of simulatenously active TCP
   connections. */
#define MEMP_NUM_TCP_PCB        35
/* MEMP_NUM_TCP_PCB_LISTEN: the number of listening TCP
   connections. */
#define MEMP_NUM_TCP_PCB_LISTEN 7
/* MEMP_NUM_TCP_SEG: the number of simultaneously queued TCP
   segments. */
#define MEMP_NUM_TCP_SEG        66
/* MEMP_NUM_SYS_TIMEOUT: the number of simulateously active
   timeouts. */
#define MEMP_NUM_SYS_TIMEOUT    10
#define MEMP_NUM_PPP_PCB 1

#define MEMP_NUM_NETCONN 26
/* PBUF_POOL_SIZE: the number of buffers in the pbuf pool. */
#define PBUF_POOL_SIZE          20

/* PBUF_POOL_BUFSIZE: the size of each pbuf in the pbuf pool. */
#define PBUF_POOL_BUFSIZE       LWIP_MEM_ALIGN_SIZE(TCP_MSS+40+PBUF_LINK_HLEN)

/**
 * MEMP_NUM_NETDB: the number of concurrently running lwip_addrinfo() calls
 * (before freeing the corresponding memory using lwip_freeaddrinfo()).
 */
#define MEMP_NUM_NETDB                  10

#define MEMP_NUM_NETBUF                 10

/* ---------- TCP options ---------- */
#define LWIP_TCP                1
#define TCP_TTL                 255

/* Controls if TCP should queue segments that arrive out of
   order. Define to 0 if your device is low on memory. */
#define TCP_QUEUE_OOSEQ         1

/* TCP Maximum segment size. */
#define TCP_MSS                 (1500 - 40)      /* TCP_MSS = (Ethernet MTU - IP header size - TCP header size) */

/* TCP sender buffer space (bytes). */
#define TCP_SND_BUF             (8*TCP_MSS)

/*  TCP_SND_QUEUELEN: TCP sender buffer space (pbufs). This must be at least
  as much as (2 * TCP_SND_BUF/TCP_MSS) for things to work. */

#define TCP_SND_QUEUELEN        (8* TCP_SND_BUF/TCP_MSS)

/* TCP receive window. */
#define TCP_WND                 (4*TCP_MSS)


/* ---------- ICMP options ---------- */
#define LWIP_ICMP                       1

/* ---------- DHCP options ---------- */
/* Define LWIP_DHCP to 1 if you want DHCP configuration of
   interfaces. DHCP is not implemented in lwIP 0.5.1, however, so
   turning this on does currently not work. */
#define LWIP_DHCP               1


/* ---------- UDP options ---------- */
#define LWIP_UDP                1
#define UDP_TTL                 255


#define LWIP_PROVIDE_ERRNO    1


/*
   --------------------------------------
   ---------- Checksum options ----------
   --------------------------------------
*/

/*
The STM32F4x7 allows computing and verifying the IP, UDP, TCP and ICMP checksums by hardware:
 - To use this feature let the following define uncommented.
 - To disable it and process by CPU comment the  the checksum.
*/
//#define CHECKSUM_BY_HARDWARE

/*
   ----------------------------------------------
   ---------- Sequential layer options ----------
   ----------------------------------------------
*/
/**
 * LWIP_NETCONN==1: Enable Netconn API (require to use api_lib.c)
 */
#define LWIP_NETCONN                    1

/*
   ------------------------------------
   ---------- Socket options ----------
   ------------------------------------
*/
/**
 * LWIP_SOCKET==1: Enable Socket API (require to use sockets.c)
 */
#define LWIP_SOCKET                     1

/**
 * LWIP_TCP_KEEPALIVE==1: Enable TCP_KEEPIDLE, TCP_KEEPINTVL and TCP_KEEPCNT
 * options processing. Note that TCP_KEEPIDLE and TCP_KEEPINTVL have to be set
 * in seconds. (does not require sockets.c, and will affect tcp.c)
 */
#define LWIP_TCP_KEEPALIVE              1

/**
 * LWIP_SO_RCVTIMEO==1: Enable receive timeout for sockets/netconns and
 * SO_RCVTIMEO processing.
 */
#define LWIP_SO_RCVTIMEO                1

//#define LWIP_PTP 1

/*
   ----------------------------------
   ---------- DNS options -----------
   ----------------------------------
*/
/**
 * LWIP_DNS==1: Turn on DNS module. UDP must be available for DNS
 * transport.
 */
#ifndef LWIP_DNS
#define LWIP_DNS                        1
#endif

/** DNS maximum number of entries to maintain locally. */
#define DNS_TABLE_SIZE                  4

/** DNS maximum host name length supported in the name table. */
#define DNS_MAX_NAME_LENGTH             256

/** The maximum of DNS servers */
#define DNS_MAX_SERVERS                 4

/** DNS do a name checking between the query and the response. */
#define DNS_DOES_NAME_CHECK             1

/** DNS message max. size. Default value is RFC compliant. */
#define DNS_MSG_SIZE                    512

/** DNS_LOCAL_HOSTLIST: Implements a local host-to-address list. If enabled,
 *  you have to define
 *    #define DNS_LOCAL_HOSTLIST_INIT {{"host1", 0x123}, {"host2", 0x234}}
 *  (an array of structs name/address, where address is an u32_t in network
 *  byte order).
 *
 *  Instead, you can also use an external function:
 *  #define DNS_LOOKUP_LOCAL_EXTERN(x) extern u32_t my_lookup_function(const char *name)
 *  that returns the IP address or INADDR_NONE if not found.
 */
#define DNS_LOCAL_HOSTLIST              0

/** If this is turned on, the local host-list can be dynamically changed
 *  at runtime. */
#define DNS_LOCAL_HOSTLIST_IS_DYNAMIC   0

/*
   -----------------------------------
   ---------- DEBUG options ----------
   -----------------------------------
*/
#define LWIP_DEBUG 1
#define LWIP_STATS    1
#define LWIP_STATS_DISPLAY    1
#define MEM_STATS    1
#define MEMP_STATS    1
#define SYS_STATS    1
#define SOCKETS_DEBUG                   LWIP_DBG_ON
#define MEMP_DEBUG                      LWIP_DBG_ON

#define LWIP_PLATFORM_DIAG(x)    do {printf x;} while(0)

/*
   ---------------------------------
   ---------- OS options ----------
   ---------------------------------
*/

#define TCPIP_THREAD_STACKSIZE          16384
#define TCPIP_MBOX_SIZE                 7
#define DEFAULT_UDP_RECVMBOX_SIZE       4000
#define DEFAULT_TCP_RECVMBOX_SIZE       4000
#define DEFAULT_ACCEPTMBOX_SIZE         4000
#define DEFAULT_THREAD_STACKSIZE        1000
#define TCPIP_THREAD_PRIO               (configMAX_PRIORITIES - 1)


#define PPP_SERIAL_PORT	0
#define PPP_SUPPORT     1
#define PPPOS_SUPPORT   1
#define PAP_SUPPORT     1
#define CHAP_SUPPORT    1
#define PPP_DEBUG       1
#define LWIP_PPP_API    1

#define LWIP_ARP  1
#define IP_FORWARD 1
#define LWIP_PTP 1

#define LWIP_COMPAT_MUTEX 1

#define TCP_OVERSIZE	1

 

Share this post


Link to post
Share on other sites
13 hours ago, x893 said:

Тема вообще ни разу не актуальная.

Ставите breakpoint на эту переменную с доступом write.

И смотрите кто туда пишет.

Какую именно ситуацию Вы предлагаете отслеживать?

У меня новые соединения создаются и закрываются чуть ли не ежесекундно, так что переменная записывается часто. А данная ошибка проявляется очень редко, не каждый день. И, к сожалению, не на столе.

Я вот думаю, что еще можно в лог записать при возникновении этого ассерта, чтобы понять при анализе лога кем он был вызван. Проблема в том, что структура уже повреждена (иначе ассерта бы и не было), непонятно что писать. Разве что каждый случай записи логировать.

 

Единственное что напрягает-  это 'TCP_PCB':

MEM TCP_PCB
    avail: 35
    used: 34
    max: 35
    err: 0

Ошибки нет, но сколько я соединений разрешу ("the number of simulatenously active TCP connections."), столько система и занимает по максимуму.

Похоже на утечку ресурса, но если связь оборвать (выдернуть LAN кабель)- то "used" возвращается в 0. Значит, зомби в системе нет, все под контролем, но все занято.

Share this post


Link to post
Share on other sites
Spoiler

 

Вы случаем не закрываете (удаляете) netconn в потоке отличном от потока где netconn_recv ? 

если #define LWIP_NETCONN  равен 1 то #define LWIP_SOCKET  должен быть 0

так же советую посмотреть и разобраться с #define LWIP_NETCONN_FULLDUPLEX именно эта опция позволяет работать с одним netconn из разных потоков, но с нюансами

Share this post


Link to post
Share on other sites
3 hours ago, x893 said:

В правилах breakpoint можно не просто запись отслеживать, а запись + переменная == 0.

 

1) Данная структура создается динамически с помощью malloc() для каждого снового соединения и удаляется, так что никаких постоянных известных адресов для указания в брейкпоинте просто нет.

2) даже если сделать статически(муторно, но теоретически можно), - я не могу поставить десятки брэйкпроинов на все нужные копии этой структуры в памяти  - столько просто не поддерживается.  Разве что новый процесс, периодически проверяющий эти адреса, и выдающий в лог тот момент, когда переменная испорчена. Может, что-то из этого вытащить можно.

В-общем, путь с брэйкпоинтами мало подходит для динамически выделяемой памяти, да еще и если проблема редкая.

 

 

3 hours ago, vadon said:

Вы случаем не закрываете (удаляете) netconn в потоке отличном от потока где netconn_recv ? 

если #define LWIP_NETCONN  равен 1 то #define LWIP_SOCKET  должен быть 0

так же советую посмотреть и разобраться с #define LWIP_NETCONN_FULLDUPLEX именно эта опция позволяет работать с одним netconn из разных потоков, но с нюансами

Огроменное спасибо!

Да, есть такая засада, у меня NETCONN и SOCKET одновременно разрешены. Буду думать и проверять.

Про разные задачи- проверю снова. Очень даже возможно.

 

'LWIP_NETCONN_FULLDUPLEX' - вообще не вижу в моей версии LwIP (1.4.1). Это, думаю, уже в "двойке" добавили,

Кстати, а имеет смысл на новый LwIP с моей 1.4.1 переходить? Каждые полгода опять начинаю думать про переход, особенно когда ковырять нужно как сейчас.

Share this post


Link to post
Share on other sites

несколько замечаний. Думаю, это касается многих кто использует LwIP 1.4.1.

1. существует многолетний баг во время создания мейлбоксов. Что бы ни задавали, всегда создается очередь дефолтовой длины. Это отлично описано athlon64 тут

2. порт freeRTOS для stm32: Если перейти на новый freeRTOS и не изменить прерывание (ETH_IRQHandler), то могут быть проблемы: в прерывании используется счетный семафор, а FreeRTOS имеет Assert на это дело. Нужно применять бинарный семафор. Описано тут. Пишут, что актуально для FreeRTOS после 8.1.2.

Эта проблема с ассертом еще интересна вот чем: по езернету качаю нон-стоп (в основном передача). Но первый переход на строку вызова xSemaphoreGiveFromISR() в приведенном ниже коде произошел где-то через 7 часов после старта. То есть ассерта можно долго ждать и отлаживать непросто. До фиксации описанного в (1) бага я вообще этого ассерта не видел, даже не понимаю почему.

void ETH_IRQHandler(void)
{
  portBASE_TYPE xHigherPriorityTaskWoken = pdFALSE;

  /* Frame received */
  if (ETH_GetDMAFlagStatus(ETH_DMA_FLAG_R) == SET) {
    /* Give the semaphore to wakeup LwIP task */
    xSemaphoreGiveFromISR(s_xSemaphore, &xHigherPriorityTaskWoken);
  }

  /* Clear the interrupt flags. */
  /* Clear the Eth DMA Rx IT pending bits */
  ETH_DMAClearITPendingBit(ETH_DMA_IT_R);
  ETH_DMAClearITPendingBit(ETH_DMA_IT_NIS);

  /* Switch tasks if necessary. */
  if (xHigherPriorityTaskWoken != pdFALSE) {
    portEND_SWITCHING_ISR(xHigherPriorityTaskWoken);
  }
}

 

Выводы из всего вышенаписанного: при изменении одного из компонентов нужно смотреть на совместимость. Если оно работает это еще не значит что оно совместимо. У меня, например, переход на более свежий freeRTOS 8.2.1 был сделан несколько лет назад, а несовместимость обнаружил только сейчас. ну и вызывает удивление многолетняя работа с багом #1... :)

Share this post


Link to post
Share on other sites

Поправка:

Прерывание ETH_IRQHandler() вызывается постоянно. вызов xSemaphoreGiveFromISR() происходит постоянно.

Но иногда (очень редко) происходит ассерт в queue.c во время этого вызова.

Вызывающая функция:

 

void ETH_IRQHandler(void)
{
  portBASE_TYPE xHigherPriorityTaskWoken = pdFALSE;

  /* Frame received */
  if (ETH_GetDMAFlagStatus(ETH_DMA_FLAG_R) == SET) {
    /* Give the semaphore to wakeup LwIP task */
    xSemaphoreGiveFromISR(s_xSemaphore, &xHigherPriorityTaskWoken);
  }

  /* Clear the interrupt flags. */
  /* Clear the Eth DMA Rx IT pending bits */
  ETH_DMAClearITPendingBit(ETH_DMA_IT_R);
  ETH_DMAClearITPendingBit(ETH_DMA_IT_NIS);

  /* Switch tasks if necessary. */
  if (xHigherPriorityTaskWoken != pdFALSE) {
    portEND_SWITCHING_ISR(xHigherPriorityTaskWoken);
  }
}

редко возникающий assert

configASSERT( !( ( pxQueue->uxQueueType == queueQUEUE_IS_MUTEX ) && ( pxQueue->pxMutexHolder != NULL ) ) ); 

внутри xSemaphoreGiveFromISR() :

BaseType_t xQueueGiveFromISR( QueueHandle_t xQueue, BaseType_t * const pxHigherPriorityTaskWoken )
{
BaseType_t xReturn;
UBaseType_t uxSavedInterruptStatus;
Queue_t * const pxQueue = ( Queue_t * ) xQueue;

	/* Similar to xQueueGenericSendFromISR() but used with semaphores where the
	item size is 0.  Don't directly wake a task that was blocked on a queue
	read, instead return a flag to say whether a context switch is required or
	not (i.e. has a task with a higher priority than us been woken by this
	post). */

	configASSERT( pxQueue );

	/* xQueueGenericSendFromISR() should be used instead of xQueueGiveFromISR()
	if the item size is not 0. */
	configASSERT( pxQueue->uxItemSize == 0 );

	/* Normally a mutex would not be given from an interrupt, and doing so is
	definitely wrong if there is a mutex holder as priority inheritance makes no
	sense for an interrupts, only tasks. */
	configASSERT( !( ( pxQueue->uxQueueType == queueQUEUE_IS_MUTEX ) && ( pxQueue->pxMutexHolder != NULL ) ) );

 

assert у меня такой:

#define configASSERT( x ) if( ( x ) == 0 ) { taskDISABLE_INTERRUPTS(); printf("FreeRTOS: Config Assert f:'%s',l:%d\r\n", (uint8_t *)__FILE__, __LINE__);for( ;; ); }

#define taskDISABLE_INTERRUPTS()	portDISABLE_INTERRUPTS()
#define portDISABLE_INTERRUPTS()				vPortRaiseBASEPRI()
static portFORCE_INLINE void vPortRaiseBASEPRI( void )
{
uint32_t ulNewBASEPRI = configMAX_SYSCALL_INTERRUPT_PRIORITY;

	__asm
	{
		/* Set BASEPRI to the max syscall priority to effect a critical
		section. */
		msr basepri, ulNewBASEPRI
		dsb
		isb
	}
}

 

После останова смотрю дебагером- все значения корректны, и результат проверки не может вызвать assert. Если принудительно перехожу на следующую строку в коде и выполняю дальше- все нормально выполняется, никаких проблем не вижу. Думал какое-то вложенное прерывание с некорректным приоритетом гадит в FreeRTOS- нет, все нормально и условия вызова не нарушены (проверил реальные регистры в NVIC после останова- что именно разрешено в системе и какие приоритеты имеет).

Полтергейст какой-то.

 

Upd: не понимаю. Такое ощущение, что где-то проблемы из-за использование не cоответствующих друг другу портов для FreeRTOS и lwIP, или внутренние проблемы. Думаю, нужно обновить мои версии 3-5 - летней давности на более новые.  Может, это давно пофиксили, а я копаюсь в старье. Как я вижу, сейчас обработка очереди немного по другому сделана в новых версиях.

Share this post


Link to post
Share on other sites

Join the conversation

You can post now and register later. If you have an account, sign in now to post with your account.

Guest
Reply to this topic...

×   Pasted as rich text.   Paste as plain text instead

  Only 75 emoji are allowed.

×   Your link has been automatically embedded.   Display as a link instead

×   Your previous content has been restored.   Clear editor

×   You cannot paste images directly. Upload or insert images from URL.

Sign in to follow this