You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mynewt.apache.org by Łukasz Rymanowski <lu...@codecoup.pl> on 2021/08/02 09:04:29 UTC
Re: NimBLE stops working after ~24h
Hi,
On Sat, 31 Jul 2021 at 13:43, <jf...@codingfield.com> wrote:
> Hello!
>
> I'm working on the InfiniTime project, an open source firmware for the
> PineTime from Pine64. It's based on the NRF52832 MCU.
> InfiniTime is running on FreeRTOS and uses NimBLE as BLE stack.
>
> By the way : thanks everyone working on this project! Thanks to you, we
> can build a 100% open source firmware for our smartwatch, which is
> great! Thanks also to this mailing list that have already helped us a
> couple of times!
>
> I'm trying to analyze a strange issue we have for quite some time : BLE
> connectivity works fine (we use it to synchronise the time, send heart
> rate data, notify battery level, firmware update,...) for ~24h. After
> roughly 24h, we lose all BLE connectivity : a host device cannot connect
> to the watch, and the watch does not advertise itself when it should
> (advertising is restarted every time the watch is woken up by a push on
> the button). It looks like the ble stack just stops.
>
> I've already done a few experiments:
> - Run a BLE sniffer (the NRF sniffer based on the nrf52dk) next to the
> watch for a day : The sniffer would see all advertising messages
> whenever the watch was supposed to advertise until it saw nothing. I saw
> no strange message between the last time the sniffer saw the advertise
> messages and the time I noticed the watch was not advertising anymore.
> - Connect the debugger once BLE does not work anymore and look at the
> tasks : both LL and Host tasks were waiting for an event on their event
> queue. No deadlock or infinite loop.
> - Enable the monitor mode and log all HCI messages using btmon. I did
> this a while ago, but as far as I remember, I couldn't see anything
> wrong.
> - Change the timeout of the calls to ble_npl_eventq_get() to check if
> the tasks were running properly : they did. They just didn't receive any
> new event3
>
> So, as far as I can see, it looks like everything is running fine, but
> no new event is generated to unlock the ble tasks. So I guess I have to
> probe a bit deeper in the radio/isr code?
>
> Any suggestion to analyze this issue is welcome. What debug info can I
> add/enable to try to understand what's happening under the hood? I have
> a NRF52DK board on hand with a logic analyzer if needed.
>
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
Best
Łukasz
> The source code is here (https://github.com/JF002/InfiniTime) and we are
> using nimble 1.3 master branch commit
> 82153e744833821e20e9a8b0d61c38b2b0dbcfe1.
>
> Thanks for your help!
>
Re: NimBLE stops working after ~24h
Posted by jf...@codingfield.com.
Looks like the btnsoop file is missing from the attachements. I'll add
it again to this message. You'll also find it here :
https://seafile.codingfield.com/d/cc037cc6eec24e97b274/.
Thanks!
JF
Le 13/08/2021 21:26, jf@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 debug
>> lines
>> connected and getting HCI logs from BLE_MONITOR_RTT.
>>
>> Best
>> Łukasz
>>
>>
>> On Wed, 11 Aug 2021 at 21:09, <jf...@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_COMPLETE
>>> event
>>> 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, <jf...@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
Posted by jf...@codingfield.com.
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 debug
> lines
> connected and getting HCI logs from BLE_MONITOR_RTT.
>
> Best
> Łukasz
>
>
> On Wed, 11 Aug 2021 at 21:09, <jf...@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_COMPLETE event
>> 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, <jf...@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
Posted by Łukasz Rymanowski <lu...@codecoup.pl>.
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 debug lines
connected and getting HCI logs from BLE_MONITOR_RTT.
Best
Łukasz
On Wed, 11 Aug 2021 at 21:09, <jf...@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_COMPLETE event
> 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, <jf...@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
Posted by jf...@codingfield.com.
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_COMPLETE event
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, <jf...@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
Posted by Łukasz Rymanowski <lu...@codecoup.pl>.
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, <jf...@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
Posted by jf...@codingfield.com.
> 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