Assert in subsys/net/buf.c during concurrent UART ISR and BLE communications

[KCrawford]

I'm working on a 52840 board controller project that requires serial communication with the 9160 (on a nRF9160DK board) and BLE communications to an Android tablet. I have discovered when receiving serial data while transmitting gatt notifications results in an ASSERT generated at line 507 in subsys/net/buf.c. I have worked around this problem by serializing comm access on the 52840 (i.e. the 52840 only requests serial data from the 9160 when it's finished with BLE access). While this works, I would prefer to allow the 9160 to send data indepent of BLE comms on the 52840. Can you explain why I am seeing this ASSERT? Is this a known problem with a known solution?

I have attached my UART ISR code and screenshots of the 52840 overlay and other relevant code. Thanks in advance for your assistance.

Fullscreen isr_code.c Download

static void uart_isr(const struct device *unused, void *user_data)
{
  static slip_t slip = { .state = SLIP_STATE_DECODING,
                         .p_buffer = slip_buffer,
                         .current_index = 0,
                         .buffer_len = sizeof(slip_buffer) 
                       };
  uint8_t byte=0;
  int ret_code=0;


  ARG_UNUSED(unused);
  ARG_UNUSED(user_data);

  while (uart_irq_update(uart_dev) && uart_irq_is_pending(uart_dev)) 
  {
    if (!uart_irq_rx_ready(uart_dev)) 
    {
        if (uart_irq_tx_ready(uart_dev)) {
                printk("transmit ready\n");
        } else {
                printk("spurious interrupt\n");
        }
        // Only the UART RX path is interrupt-enabled 
        break;
    }


    uart_fifo_read(uart_dev, &byte, sizeof(byte));
    ret_code = slip_decode_add_byte(&slip, byte);

    switch (ret_code) 
    {
      case UART_PACKET_RECIEVED_SUCCESS: 
      {
        uint16_t checksum_local = crc16_ansi(slip.p_buffer, slip.current_index - CHECKSUM_SIZE);
        uint16_t checksum_incoming;

        memcpy(&checksum_incoming, slip.p_buffer + (slip.current_index - CHECKSUM_SIZE),  sizeof(checksum_incoming));

        if (checksum_incoming == checksum_local) 
        {
            struct net_buf *buf = net_buf_alloc_len(&uart_pool, slip.current_index - CHECKSUM_SIZE, K_NO_WAIT);
            net_buf_add_mem(buf, slip.p_buffer, slip.current_index - CHECKSUM_SIZE);
            net_buf_put(&tx_queue, buf);
        } 
        else 
        {
            //printk("Invalid Checksum %02x vs %02x\n",checksum_incoming,checksum_local);
            printk("Invalid Checksum x%04x vs x%04x, len=%d\n",checksum_incoming,checksum_local,slip.current_index);
            //buf2hex(slip.p_buffer,slip.current_index);
        }
      }
              // fall through
      case -ENOMEM:
          slip.current_index = 0;
          slip.state = SLIP_STATE_DECODING;
          break;

      default:
          break;
    }
  }
}

[Simon]

I can see that you run *buf = net_buf_alloc_len(&uart_pool,..) first. My suspicion is that uart_pool is out of buffers and it will return null (and buf will then be equal to NULL), as stated in the explanatory text above net_buf_alloc_len(). Could you try to figure out where you define uart_pool and try to increase the size?

Best regards,

Simon

[KCrawford]

Hello again Simon. Thanks for the fast response and insight as to the problem I am sending somewhat large packets (around 1024 bytes) between the 9160<>52840 at about 500ms intervals. That doesn't seem like much, but BLE and sensor sampling are going concurrently as well. I will research how to check/set the uart_pool and get back to you ASAP. Thanks again for your expertise and help.

[KCrawford]

Hey Simon, I have inserted a screenshot of where a believe the buffer pool is configured. This code is from an example I found on DevZone that had sources files uart_simple.c and slip.c. I'm not sure of the link. The example as written would only handle packets 256 bytes or less. But I need to send a packet over 1000 bytes in length. So I increased the buffers for that. And had to fix an bug where the CRC index was defined as a uint8_t (hence the 256 limit). Note I did not increase the size of the UART_RX_POOL_MAX_ENTRIES define. Is that possibly the issue?

[Simon]

Yes, try to increase UART_RX_POOL_MAX_ENTRIES and see if it still asserts.

[KCrawford]

Hey Simon, I finally got a chance to test that config, but I still got the same error. I even tried to de-couple the UART event from the BLE transmit logic by inserting queue logic between them. The error changed from an ASSERT to the message "Unable to allocate TX context". At the point, BLE operations just seemed to hang. 

However, in doing more research I found a related Zephyr issue (can't remember where), and it suggested switching to a thread vs a work queue. So I switched my BLE logic to a thread and Voila! Success. So this seems like an issue in the Zephyr logic somewhere. But at least I'm able to make progress again. Thanks for your help.