h5_decode error, code: 0x802c, H5 error count

[Wael]

Hi,

I am getting this error message when using the nRF52 dev board but not when using the nRF51 dongle. I receive few packets and then it disconnects with this error message. here is the log from nRFConnect(version 3.6.1) desktop Bluetooth Low Energy application. I am connecting to an nRF52832 target device with an in house developed application that we have been using for years. 

it’s the nRFConnect that’s faulting because I can see the nRFConnect disconnect with the error message and the target device doesn’t disconnect until few seconds later with BLE_HCI_CONNECTION_TIMEOUT. I cant seem to find any information on this error that is helpful. any help is greatly appreciated. 

4857.2021-05-24T15_07_05.686Z-log.txt

and the log from terminal is this:

13> [00:00:00.000,000] <info> app: Event: FDS_EVT_INIT received (FDS_SUCCESS)
13> [00:00:00.000,000] <info> app: Read Record 0:
13> [00:00:00.000,000] <info> app: 00 FF FF FF FF FF FF FF|.
13> [00:00:00.000,000] <info> app: FF FF FF FF FF FF FF 00|.
13> [00:00:00.000,000] <info> app: 75 FF 00 00 |u..
13> [00:00:00.000,030] <info> app:
13>
13> [00:00:00.000,030] <info> app: Flash Record #1 NOT Found:
13> [00:00:00.000,061] <info> app: Event: FDS_EVT_INIT received (FDS_SUCCESS)
13>
13>
13>
13> [00:00:00.268,218] <debug> nrf_ble_gatt: Updating data length to 251 on connection 0x0.
13> [00:00:00.268,218] <error> nrf_ble_gatt: sd_ble_gap_data_length_update() (request) on connection 0x0 returned NRF_ERROR_RESOURCES.
13> [00:00:00.268,218] <error> nrf_ble_gatt: The requested TX/RX packet length is too long by 224/224 octets.
13> [00:00:00.268,249] <info> app: Unknown Acquisition Mode: 4
13> [00:00:00.268,249] <info> app: Acquisition Mode Updated to: 4
13> [00:00:00.268,249] <info> app: Connected
13> [00:00:00.280,364] <info> app: m_conn_handle = 0x0
13> [00:00:00.280,395] <info> app: PM Event: 5
13> [00:00:00.280,395] <info> app: PM Event: PM_EVT_CONN_SEC_PARAMS_REQ
13> [00:00:00.280,395] <info> app: Start encryption, pm_conn_secure returned 0
13> [00:00:00.286,285] <info> app: PM Event: 1
13> [00:00:00.286,285] <info> app: PM Event: 5
13> [00:00:00.286,285] <info> app: PM Event: PM_EVT_CONN_SEC_PARAMS_REQ
13> [00:00:00.286,315] <info> app: BLE_GAP_EVT_SEC_PARAMS_REQUEST
13> [00:00:00.286,315] <info> app: Passkey: 086574
13> [00:00:00.523,895] <info> app: BLE_GAP_EVT_CONN_SEC_UPDATE EVENT Received
13> [00:00:00.523,895] <info> app: PM Event: 2
13> [00:00:00.523,925] <info> app: Link secured. Role: 1. conn_handle: 0, Procedure: 2
13> [00:00:00.606,964] <info> app: PM Event: 14
13> [00:00:00.664,916] <info> app: max connection interval: 18
13>
13> [00:00:00.664,916] <info> app: min connection interval: 16
13>
13> [00:00:00.664,916] <info> app: err_code = 0x0 in update_conn_params
13> [00:00:00.664,947] <info> app: Acquisition Mode Updated to: 0
13> [00:00:00.665,527] <info> app: Transmit err_code = 0
13> [00:00:00.665,557] <info> app: hvn_tx_queue_count = 7, m_tx_queue_busy = 0
13> [00:00:00.665,557] <info> app: Transmit err_code = 0
13> [00:00:00.665,557] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.665,588] <info> app: Packet TX Complete Time = 713818, hvn_tx_queue_count = 7
13> [00:00:00.666,137] <info> app: Transmit err_code = 0
13> [00:00:00.666,137] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.666,168] <info> app: Transmit err_code = 0
13> [00:00:00.666,168] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.666,198] <info> app: Packet TX Complete Time = 636, hvn_tx_queue_count = 6
13> [00:00:00.666,198] <info> app: Packet TX Complete Time = 23, hvn_tx_queue_count = 7
13> [00:00:00.666,748] <info> app: Transmit err_code = 0
13> [00:00:00.666,748] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.666,748] <info> app: Transmit err_code = 0
13> [00:00:00.666,778] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.666,839] <info> app: Packet TX Complete Time = 673, hvn_tx_queue_count = 6
13> [00:00:00.666,839] <info> app: Packet TX Complete Time = 23, hvn_tx_queue_count = 7
13> [00:00:00.667,358] <info> app: Transmit err_code = 0
13> [00:00:00.667,358] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.667,358] <info> app: Transmit err_code = 0
13> [00:00:00.667,358] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.667,480] <info> app: Packet TX Complete Time = 673, hvn_tx_queue_count = 6
13> [00:00:00.667,510] <info> app: Packet TX Complete Time = 23, hvn_tx_queue_count = 7
13> [00:00:00.667,968] <info> app: Transmit err_code = 0
13> [00:00:00.667,968] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.667,968] <info> app: Transmit err_code = 0
13> [00:00:00.667,968] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.668,121] <info> app: Packet TX Complete Time = 673, hvn_tx_queue_count = 6
13> [00:00:00.668,151] <info> app: Packet TX Complete Time = 24, hvn_tx_queue_count = 7
13> [00:00:00.668,579] <info> app: Transmit err_code = 0
13> [00:00:00.668,579] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.668,579] <info> app: Transmit err_code = 0
13> [00:00:00.668,579] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.668,762] <info> app: Packet TX Complete Time = 673, hvn_tx_queue_count = 6
13> [00:00:00.668,792] <info> app: Packet TX Complete Time = 23, hvn_tx_queue_count = 7
13> [00:00:00.669,158] <info> app: Transmit err_code = 0
13> [00:00:00.669,189] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.669,189] <info> app: Transmit err_code = 0
13> [00:00:00.669,189] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.669,403] <info> app: Packet TX Complete Time = 673, hvn_tx_queue_count = 6
13> [00:00:00.669,433] <info> app: Packet TX Complete Time = 23, hvn_tx_queue_count = 7
13> [00:00:00.669,769] <info> app: Transmit err_code = 0
13> [00:00:00.669,769] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.669,799] <info> app: Transmit err_code = 0
13> [00:00:00.669,799] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.669,799] <info> app: Battery Count = 3323
13> [00:00:00.670,043] <info> app: Packet TX Complete Time = 678, hvn_tx_queue_count = 6
13> [00:00:00.670,074] <info> app: Packet TX Complete Time = 22, hvn_tx_queue_count = 7
13> [00:00:00.670,379] <info> app: Transmit err_code = 0
13> [00:00:00.670,379] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.670,410] <info> app: Transmit err_code = 0
13> [00:00:00.670,410] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.670,684] <info> app: Packet TX Complete Time = 674, hvn_tx_queue_count = 6
13> [00:00:00.670,989] <info> app: Transmit err_code = 0
13> [00:00:00.670,989] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.670,989] <info> app: Transmit err_code = 0
13> [00:00:00.671,020] <info> app: hvn_tx_queue_count = 4, m_tx_queue_busy = 0
13> [00:00:00.671,325] <info> app: Packet TX Complete Time = 693, hvn_tx_queue_count = 5
13> [00:00:00.671,600] <info> app: Transmit err_code = 0
13> [00:00:00.671,600] <info> app: hvn_tx_queue_count = 4, m_tx_queue_busy = 0
13> [00:00:00.671,600] <info> app: Transmit err_code = 0
13> [00:00:00.671,600] <info> app: hvn_tx_queue_count = 3, m_tx_queue_busy = 0
13> [00:00:00.671,997] <info> app: Packet TX Complete Time = 696, hvn_tx_queue_count = 4
13> [00:00:00.671,997] <info> app: Packet TX Complete Time = 22, hvn_tx_queue_count = 5
13> [00:00:00.672,027] <info> app: Packet TX Complete Time = 22, hvn_tx_queue_count = 6
13> [00:00:00.672,058] <info> app: Packet TX Complete Time = 24, hvn_tx_queue_count = 7
13> [00:00:00.672,210] <info> app: Transmit err_code = 0
13> [00:00:00.672,210] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.672,210] <info> app: Transmit err_code = 0
13> [00:00:00.672,210] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.672,637] <info> app: Packet TX Complete Time = 627, hvn_tx_queue_count = 6
13> [00:00:00.672,637] <info> app: Packet TX Complete Time = 24, hvn_tx_queue_count = 7
13> [00:00:00.672,821] <info> app: Transmit err_code = 0
13> [00:00:00.672,821] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.672,821] <info> app: Transmit err_code = 0
13> [00:00:00.672,821] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.673,278] <info> app: Packet TX Complete Time = 673, hvn_tx_queue_count = 6
13> [00:00:00.673,278] <info> app: Packet TX Complete Time = 23, hvn_tx_queue_count = 7
13> [00:00:00.673,400] <info> app: Transmit err_code = 0
13> [00:00:00.673,431] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.673,431] <info> app: Transmit err_code = 0
13> [00:00:00.673,431] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.673,919] <info> app: Packet TX Complete Time = 673, hvn_tx_queue_count = 6
13> [00:00:00.673,950] <info> app: Packet TX Complete Time = 23, hvn_tx_queue_count = 7
13> [00:00:00.673,950] <info> app: Max. conn. interval updated to 16
13> [00:00:00.673,950] <info> app: Min. conn. interval updated to 16
13> [00:00:00.674,011] <info> app: Transmit err_code = 0
13> [00:00:00.674,011] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.674,041] <info> app: Transmit err_code = 0
13> [00:00:00.674,041] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.674,560] <info> app: Packet TX Complete Time = 673, hvn_tx_queue_count = 6
13> [00:00:00.674,621] <info> app: Transmit err_code = 0
13> [00:00:00.674,621] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.674,621] <info> app: Transmit err_code = 0
13> [00:00:00.674,652] <info> app: hvn_tx_queue_count = 4, m_tx_queue_busy = 0
13> [00:00:00.675,170] <info> app: Packet TX Complete Time = 657, hvn_tx_queue_count = 5
13> [00:00:00.675,170] <info> app: Packet TX Complete Time = 21, hvn_tx_queue_count = 6
13> [00:00:00.675,201] <info> app: Packet TX Complete Time = 23, hvn_tx_queue_count = 7
13> [00:00:00.675,231] <info> app: Transmit err_code = 0
13> [00:00:00.675,231] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.675,231] <info> app: Transmit err_code = 0
13> [00:00:00.675,231] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.675,781] <info> app: Packet TX Complete Time = 610, hvn_tx_queue_count = 6
13> [00:00:00.675,781] <info> app: Packet TX Complete Time = 23, hvn_tx_queue_count = 7
13> [00:00:00.675,842] <info> app: Transmit err_code = 0
13> [00:00:00.675,842] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.675,842] <info> app: Transmit err_code = 0
13> [00:00:00.675,842] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.676,391] <info> app: Packet TX Complete Time = 632, hvn_tx_queue_count = 6
13> [00:00:00.676,391] <info> app: Packet TX Complete Time = 24, hvn_tx_queue_count = 7
13> [00:00:00.676,452] <info> app: Transmit err_code = 0
13> [00:00:00.676,452] <info> app: hvn_tx_queue_count = 6, m_tx_queue_busy = 0
13> [00:00:00.676,452] <info> app: Transmit err_code = 0
13> [00:00:00.676,452] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.676,971] <info> app: Packet TX Complete Time = 632, hvn_tx_queue_count = 6
13> [00:00:00.677,032] <info> app: Transmit err_code = 0
13> [00:00:00.677,062] <info> app: hvn_tx_queue_count = 5, m_tx_queue_busy = 0
13> [00:00:00.677,062] <info> app: Transmit err_code = 0
13> [00:00:00.677,062] <info> app: hvn_tx_queue_count = 4, m_tx_queue_busy = 0
13> [00:00:00.677,642] <info> app: Transmit err_code = 0
13> [00:00:00.677,642] <info> app: hvn_tx_queue_count = 3, m_tx_queue_busy = 0
13> [00:00:00.677,673] <info> app: Transmit err_code = 0
13> [00:00:00.677,673] <info> app: hvn_tx_queue_count = 2, m_tx_queue_busy = 0
13> [00:00:00.678,253] <info> app: Transmit err_code = 0
13> [00:00:00.678,253] <info> app: hvn_tx_queue_count = 1, m_tx_queue_busy = 0
13> [00:00:00.678,283] <info> app: Transmit err_code = 0
13> [00:00:00.678,283] <info> app: hvn_tx_queue_count = 0, m_tx_queue_busy = 0
13> [00:00:00.678,863] <info> app: ........Waiting

any help would be greatly apprecaited.

Regards

[Simonr]

Hi again

Okay, so that the "working" computer is also reporting this error now and then seems very strange. And you never see this error when using the nRF51 Dongle as the central on either computers, right?

I have to ask, but are you able to recreate this with another target device than the in-house one you have. I.E. using the nRF51 Dongle as the target device with a similar application? I have not been able to recreate it on my end with the same USB driver version and J-Link version as your faulty computers.

Can you try disabling J-Link MSD on your computer as well to see if that helps, described how to do so here. I'll see what I can do with regards to a meeting, but we generally find that "live debugging sessions" are not very efficient.

Best regards,

Simon

[Wael]

hi Simon,

I disabled the MSD on both installed versions of jlink(6.44e and 6.88a) and repowered the DK and still the same issue. I also upgraded to the new nRFConnect 3.7 and still the same issue. what exactly is the MSD?

I have tested nRFConnect with a Laird module using the heart rate example and the issue does not happen. when using the nRF51 dongle, the issue also does not happen but I do notice the packet rate transmission is much slower. 

Furthermore, using our device/app with the lightBlue app on my iPhone does not have any issues. also using it with a windows tablet doesn't seem to have any issue either. I hope this helps.

Regards,

[Wael]

any update on this? I think its time for us to setup a meeting to view this issue firsthand. your help is greatly appreciated.

Regards,

Wael

[tesc]

Hi,

I am very sorry for the delays. As earlier stated, we are now in summer holiday season in Norway, and a lot of engineers are out-of-office. This situation will continue for the remainder of July. We are doing our best looking at the issues, but it will be slower than normal during these weeks, and worst case things must wait.

I have once again asked for feedback from the team, on what can be done to move forward on this issue, and will get back to you as soon as we see a path forward.

Regards,
Terje

[Wael]

Hi Terje,

I understand, and thank you for the feedback!

Regards,

Wael

[tesc]

Hi,

Again I am sorry for the delays. It looks like we can get back to you next week. If you have done any further investigations in your end, then please share them as well.

Regards,
Terje

[Wael]

Hi Terje,

I have not done any further investigations since I could not think of anything else to check or do. I have but been waiting to hear back from you guys. I look forward to your response. 

Regards,

Wael