Re: NimBLE stops working after ~24h

jf Sat, 14 Aug 2021 09:05:08 -0700

Looks like the btnsoop file is missing from the attachements. I'll addit again to this message. You'll also find it here :https://seafile.codingfield.com/d/cc037cc6eec24e97b274/.


Thanks!
JF


Le 13/08/2021 21:26, j...@codingfield.com a écrit :

Hi Łukasz,

I ran a new test of more than 24h to get the btsnoop file. In this
file, you'll probably noticed that the advertising was started/stopped
several times. I also connected my phone a few time. The last
advertising start/stop showed the issue : logs show that the
advertising is started, by I couldn't detect those advertising
messages (with my phone and ble sniffer) and the debug pins didn't
show any activity either.

I also exported the content of all the registers at that point, in
case it can be useful.

Do you see anything interesting in those files?

Thanks for your help!

JF

Le 11/08/2021 22:38, Łukasz Rymanowski a écrit :

Hi JF,

Yes, this is expected if you set the duration to 3 minutes :)

I guess you want to reproduce your original problem now, having debuglines

connected and getting HCI logs from BLE_MONITOR_RTT.

Best
Łukasz


On Wed, 11 Aug 2021 at 21:09, <j...@codingfield.com> wrote:

Hi,

> I need to admit that I totally missed the part that you are on FreeRTOS
> but
> I see DEBUG lines that work for you.
> On the first picture you see radio activity every advertising interval
> and
> on the second one you see a single advertising event - all looks good.

Good to know that when it works, it works well :-)

> Anyway, the question now is why BLE_GAP_EVENT_ADV_COMPLETE is sent with
> a
> timeout. Did you try to debug it by setting breakpoint at
> ble_gap_adv_finished?

This is probably because advertising is started with a timeout of 3
minutes :

     ble_gap_adv_start(addrType, NULL, 180000, &adv_params,
GAPEventCallback, this);

Isn't that expected?

Anyway, here's the callstack when the BLE_GAP_EVENT_ADV_COMPLETEevent

is received:

Breakpoint 2, Pinetime::Controllers::NimbleController::OnGAPEvent
(this=0x200019e0 <systemTask+96>, event=0x20006b44 <ucHeap+8364>) at
/home/jf/git/PineTime/src/components/ble/NimbleController.cpp:137
137           NRF_LOG_INFO("Advertising event :
BLE_GAP_EVENT_ADV_COMPLETE");
(gdb) bt

#0 Pinetime::Controllers::NimbleController::OnGAPEvent(this=0x200019e0

<systemTask+96>, event=0x20006b44 <ucHeap+8364>) at
/home/jf/git/PineTime/src/components/ble/NimbleController.cpp:137
#1  0x0000e7c4 in GAPEventCallback (event=<optimized out>,
arg=<optimized out>) at
/home/jf/git/PineTime/src/components/ble/NimbleController.cpp:47
#2  0x000177cc in ble_gap_adv_finished (instance=instance@entry=0
'\000', reason=reason@entry=13, conn_handle=conn_handle@entry=0,
num_events=num_events@entry=0 '\000') at
/home/jf/git/PineTime/src/libs/mynewt-nimble/nimble/host/src/ble_gap.c:802
#3  0x00017aba in ble_gap_slave_timer () at
/home/jf/git/PineTime/src/libs/mynewt-nimble/nimble/host/src/ble_gap.c:1970
#4  0x00017d5e in ble_gap_timer () at
/home/jf/git/PineTime/src/libs/mynewt-nimble/nimble/host/src/ble_gap.c:2044
#5  0x00014a60 in ble_hs_timer_exp (ev=<optimized out>) at
/home/jf/git/PineTime/src/libs/mynewt-nimble/nimble/host/src/ble_hs.c:407
#6  0x0000b748 in ble_npl_event_run (ev=<optimized out>) at

/home/jf/git/PineTime/src/libs/mynewt-nimble/porting/npl/freertos/include/nimble/nimble_npl_os.h:115
#7  nimble_port_run () at /home/jf/git/PineTime/src/main.cpp:266

> Also could you share btsnoop logs?

Do you mean the HCI logs from BLE_MONITOR_RTT I get using btmon ?I'll

let it run overnight to get fresh logs.

Thanks,
JF


Le 06/08/2021 10:45, Łukasz Rymanowski a écrit :
> Hi JF,
>
> I need to admit that I totally missed the part that you are on FreeRTOS
> but
> I see DEBUG lines that work for you.
> On the first picture you see radio activity every advertising interval
> and
> on the second one you see a single advertising event - all looks good.
>
> Anyway, the question now is why BLE_GAP_EVENT_ADV_COMPLETE is sent with
> a
> timeout. Did you try to debug it by setting breakpoint at
> ble_gap_adv_finished?
> Also could you share btsnoop logs?
>
> Bes
> Łukasz
>
>
> On Tue, 3 Aug 2021 at 20:37, <j...@codingfield.com> wrote:
>
>> > If you have nrf52 you could trace radio activity with some debug pins
>> > BLE_PHY_DBG_TIME_ADDRESS_END_PIN
>> > BLE_PHY_DBG_TIME_WFR_PIN
>> > BLE_PHY_DBG_TIME_TXRXEN_READY_PIN
>> >
>> > Here you can find a description of those.
>> >
>>
https://github.com/apache/mynewt-nimble/blob/master/nimble/drivers/nrf52/syscfg.yml#L35
>>
>> Thanks Łukasz! I've connected my logic analyzer (saleae logic 8) on 3
>> pins, and I've also enabled the logging feature of nimble.
>> When BLE is working fine and start advertising, I can see this in the
>> logs :
>>
>> <info> app: GAP procedure initiated: advertise;
>> <info> app: disc_mode=2
>> <info> app:  adv_channel_map=0 own_addr_type=0 adv_filter_policy=0
>> adv_itvl_min=0 adv_itvl_max=0
>> <info> app:
>>
>> And when it stops, after 3 minutes:
>>
>> <info> app: Advertising event : BLE_GAP_EVENT_ADV_COMPLETE
>> <info> app: advertise complete; reason=13n status=13
>>
>> See ble-adv1.png and ble-adv2.png for screenshots of the capture of
>> the
>> 3 pins.
>>
>> I left the device running during the whole day and in the evening, I
>> tried to restart the advertising (with a push button) and... the logs
>> are exactly the same (as if it was advertising correctly for 3 minutes
>> and then complete) but... nothing on the 3 debug pins, they were just
>> flat on low level. Obviously, the device was not found by my ble
>> scanner.
>>
>> Sooo... any ideas :p ?
>>
>> Thanks!
>>
>> JF

Re: NimBLE stops working after ~24h

Reply via email to