Nimble throughput example `NimBLE: exp_time:0.now:12755.ticks:3939.active:1.Need reset.` error (IDFGH-7004)

[listout]

What does this error even mean? I can't find anything about this error on the internet. I'm using IDF from the master branch and I'm constantly facing issues with NimBLE stack (I'm prototyping hence the master branch).

Issue is in the blecent_throughput example

[rahult-github]

Hi @listout ,

The print should be under debug tag rather than error tag, as it is just a condition to call timer reset. Also, it is just a information print and ideally should not cause any issue. Can you elaborate the issue because of this message you are observing ?

Thanks, Rahul

[listout]

Hi @rahult-github basically the sketch is not working as intended (can't write/read/notify). I was testing out the examples from the master branch and haven't changed anything so I don't actually know why this line is under the Error tag instead of debug. From the central project when I try to write (throughput write 100) I get the following log

Throughput demo >> throughput write 100
I (68013) Throughput demo handler: throughput write 100
E (68503) blecent_throughput:  Read failed, callback error code = 13
I (68503) NimBLE: GAP procedure initiated: terminate connection; conn_handle=0 hci_reason=19

I (68503) NimBLE: GATT procedure initiated: read;
I (68513) NimBLE: att_handle=17

E (68523) blecent_throughput:  Read failed, callback error code = 7
I (68523) NimBLE: GATT procedure initiated: read;
I (68523) blecent_throughput: disconnect; reason=534
I (68523) NimBLE: att_handle=17

                                                                                                                                                                                                                                             I (68543) blecent_throughput:

E (68543) blecent_throughput: Error: Failed to read characteristic; rc=7
I (68553) NimBLE: GAP procedure initiated: discovery;
I (68563) NimBLE: own_addr_type=0 filter_policy=0 passive=1 limited=0 filter_duplicates=1
I (68563) NimBLE: duration=forever
I (68573) NimBLE:

I (68643) blecent_throughput: Event DISC
I (68643) blecent_throughput: connect; fields.num_uuids128 =0
I (68643) blecent_throughput: Device Name = nimble_prph

E (68653) blecent_throughput: Error while reading from GATTS; rc = 7
I (68653) blecent_throughput: central connect to `nimble_prph` success
I (68673) NimBLE: GAP procedure initiated: connect;
I (68673) NimBLE: peer_addr_type=0 peer_addr=
I (68683) NimBLE: 58:bf:25:32:e3:1a
I (68683) NimBLE:  scan_itvl=16 scan_window=16 itvl_min=24 itvl_max=40 latency=0 supervision_timeout=256 min_ce_len=0 max_ce_len=0 own_addr_type=0
I (68693) NimBLE:

I (68743) blecent_throughput: Connection established
E (68753) blecent_throughput: Failed to set preferred MTU; rc = 3
I (68753) NimBLE: GATT procedure initiated: exchange mtu

E (68763) blecent_throughput: Failed to update params; rc = 3
I (68773) NimBLE: GATT procedure initiated: discover all services

Throughput demo >> I (68873) blecent_throughput: mtu update event; conn_handle = 0 cid = 4 mtu = 512
I (68963) NimBLE: GATT procedure initiated: discover all characteristics;
I (68973) NimBLE: start_handle=1 end_handle=5

I (69163) NimBLE: GATT procedure initiated: discover all characteristics;
I (69173) NimBLE: start_handle=6 end_handle=9

I (69363) NimBLE: GATT procedure initiated: discover all characteristics;
I (69373) NimBLE: start_handle=10 end_handle=65535

I (69563) NimBLE: GATT procedure initiated: discover all descriptors;
I (69573) NimBLE: chr_val_handle=8 end_handle=9

I (69663) NimBLE: GATT procedure initiated: discover all descriptors;
I (69673) NimBLE: chr_val_handle=14 end_handle=15

I (69763) NimBLE: GATT procedure initiated: discover all descriptors;
I (69773) NimBLE: chr_val_handle=17 end_handle=65535

I (69863) blecent_throughput: Service discovery complete; status=0 conn_handle=0

I (73873) blecent_throughput: Format for throughput demo:: throughput read 100
 ==================================================================
 |                 Steps to test nimble throughput                |
 |                                                                |
 |  1. Enter throughput [--Type] [--Test time]                    |
 |  Type: read/write/notify.                                      |
 |  Test time: Enter value in seconds.                            |
 |                                                                |
 |  e.g. throughput read 600                                      |
 |                                                                |
 |  ** Enter 'throughput read 60' for reading char for 60 seconds |
 |  OR 'throughput write 60' for writing to char for 60 seconds   |
 |  OR 'throughput notify 60' for notifications (for 60 seconds)**|
 |                                                                |
 =================================================================

I (77653) blecent_throughput: Format for throughput demo:: throughput read 100

Following log from the central project

I (185298) bleprph_throughput: disconnect; reason = 531
I (185308) NimBLE: GAP procedure initiated: advertise;
I (185308) NimBLE: disc_mode=2
I (185308) NimBLE:  adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
I (185318) NimBLE:

Also the exp_time is still under Error, I'm trying the examples from the master branch that I've just now cloned.

[listout]

Also the command throughput read 100 does nothing, I mean like the readme of the sketch shows and there is almost no update (on the terminal) on the central app. The only update are of connect, disconnect and connection update (again not matching with the readme of the peripheral example)

I just increased the nimble log verbosity to debug, still not change in the output (on terminal).

[rahult-github]

Hi @listout , I tried the example at my end, and able to see it functioning at my end. Attached is the output i see when i ran "throughput write 20" . write_output.txt

Can you please help share some more updates that will help me narrow down the failure and debug:

1. Can you please confirm the commit id you are observing this issue on ?
2. Can you please confirm git submodule update recursive is done and git pull also cleanly done to ensure correct codebase.
3. Please confirm you are also running bleprph_throughput app

Thanks, Rahul