9 Replies Latest reply on May 15, 2017 9:17 AM by AxLi_1746341

    GKI_exception 65524 getbuf: out of buffers

    AxLi_1746341

      I finally have a chance to test latest BT library with the wiced_bt_print_cfg_buf_pool_stats().

       

      The normal case:

      It usually only uses Small Buffer Pool and Medium Buffer Pool.

       

      00:00:46.055248 GKI_create_task func=0x8068651  id=1  name=BTU  stack=0x0  stackSize=6144␍␍␊

      00:00:46.063248 GKI_create_task func=0x8069b71  id=0  name=HCISU  stack=0x0  stackSize=4096␍␍␊

      00:03:24.037032 ␍␍␊

      00:03:24.038032 --- Bluetooth(Pool type: A-App, I-Internal) Buffer summary ---␍␍␊

      00:03:24.046032 Pool(size,type)   Available   In-use    Total   Max-used␍␍␊

      00:03:24.051032 --------------------------------------------------------␍␍␊

      00:03:24.056032 00(  64, A):          16,       0,      16,       5␍␍␊

      00:03:24.063032 01( 360, A):           6,       0,       6,       3␍␍␊

      00:03:24.003496 02( 360, A):           6,       0,       6,       0␍␍␊

      00:03:24.010496 03( 600, A):           2,       0,       2,       0␍␍␊

      00:28:13.040248 ␍␍␊

      00:28:13.041248 --- Bluetooth(Pool type: A-App, I-Internal) Buffer summary ---␍␍␊

      00:28:13.045248 Pool(size,type)   Available   In-use    Total   Max-used␍␍␊

      00:28:13.005712 --------------------------------------------------------␍␍␊

      00:28:13.008712 00(  64, A):          16,       0,      16,       5␍␍␊

      00:28:13.013712 01( 360, A):           6,       0,       6,       4␍␍␊

      00:28:13.021712 02( 360, A):           6,       0,       6,       0␍␍␊

      00:28:13.024712 03( 600, A):           2,       0,       2,       0␍␍␊

      00:59:51.011032 ␍␍␊

      00:59:51.012032 --- Bluetooth(Pool type: A-App, I-Internal) Buffer summary ---␍␍␊

      00:59:51.021032 Pool(size,type)   Available   In-use    Total   Max-used␍␍␊

      00:59:51.023032 --------------------------------------------------------␍␍␊

      00:59:51.027032 00(  64, A):          16,       0,      16,       5␍␍␊

      00:59:51.031032 01( 360, A):           5,       1,       6,       4␍␍␊

      00:59:51.037032 02( 360, A):           6,       0,       6,       0␍␍␊

      00:59:51.043032 03( 600, A):           2,       0,       2,       0␍␍␊

       

      The abnormal case:

      From the Max-used field, you can find it actually run out of all buffers.

       

      00:01:01.008856 GKI_create_task func=0x8068651  id=1  name=BTU  stack=0x0  stackSize=6144␍␍␊

      00:01:01.016856 GKI_create_task func=0x8069b71  id=0  name=HCISU  stack=0x0  stackSize=4096␍␍␊

      01:58:07.064392 GKI_exception(): Task State Table␍␍␊

      01:58:07.063856 GKI_exception 65524 getbuf: out of buffers␍␍␊

      03:04:18.027928 ␍␍␊

      03:04:18.028928 --- Bluetooth(Pool type: A-App, I-Internal) Buffer summary ---␍␍␊

      03:04:18.036928 Pool(size,type)   Available   In-use    Total   Max-used␍␍␊

      03:04:18.043928 --------------------------------------------------------␍␍␊

      03:04:18.049928 00(  64, A):          12,       4,      16,       5␍␍␊

      03:04:18.056928 01( 360, A):           6,       0,       6,       6␍␍␊

      03:04:18.062928 02( 360, A):           6,       0,       6,       6␍␍␊

      03:04:18.003392 03( 600, A):           2,       0,       2,       2␍␍␊

      03:05:15.054928 ␍␍␊

      03:05:15.056928 --- Bluetooth(Pool type: A-App, I-Internal) Buffer summary ---␍␍␊

      03:05:15.063928 Pool(size,type)   Available   In-use    Total   Max-used␍␍␊

      03:05:15.005392 --------------------------------------------------------␍␍␊

      03:05:15.012392 00(  64, A):          12,       4,      16,       5␍␍␊

      03:05:15.018392 01( 360, A):           6,       0,       6,       6␍␍␊

      03:05:15.024392 02( 360, A):           6,       0,       6,       6␍␍␊

      03:05:15.031392 03( 600, A):           2,       0,       2,       2␍␍␊

       

      So my question is why the BT library suddently request so many Large Buffer Pool and Extra Large Buffer Pool.

      What happens so the bt library needs large buffer pool and extra large buffer poll?

      In my use case, I only call wiced_bt_ble_observe() to scan tags.

       

      I don't think this is a normal thing as in above normal case it never request Large Buffer Pool and Extra Large Buffer Pool at all.

      ps. In most of the debug print I can see the In-use number is usually very small.

      I have no idea what's going on with the abnormal case. It looks like a bug.

      And I have no idea how to config the buffers in such case as the Max-used number seems suddenly growth.

       

      Appreciate if someone from cypress can help.

       

      dharamk_91 JaeyoungY_71 rameshm_61

        • 1. Re: GKI_exception 65524 getbuf: out of buffers
          AxLi_1746341

          BTW, wiced_bt_print_cfg_buf_pool_stats() is pretty bad design because it relies on STDIO.

          I only have a few develop boards with uart output.

          Most of my test devices does not have uart output.

          So I cannot get the statistics number on the devices without uart output.

          I can get Available   In-use    Total buffer count by using GKI_poolfreecount APIs.

          However, there is no API to get the most import value: the Max-used count.

          I think you should provide the api to get Max-used count.

          • 2. Re: GKI_exception 65524 getbuf: out of buffers
            DaBa_2244756

            Hi Axel.

            One note.

            Wiced ble stack have "Read" task with very love priorities(1).

            Maybe other task with  bigger priorities some times have

            big load. Then ble "Read" task can't handle ble buffers.

            For test try to do all your  task priorities to (1).

            Darius

            • 3. Re: GKI_exception 65524 getbuf: out of buffers
              AxLi_1746341

              I disgreee.

              The BT stack should work no matter the prioity fo other applications threads.

              Otherwise it's simply too buggy to work.

               

              In additional, my observation shows it usually uses very few buf_count.

              If I don't know the reason why it takes many buf_count, there is no way to

              properly config the buf_count settings. The buf_count settings needs to work

              for the worst case, however I don't know how many buffers are required for the worst case.

              • 4. Re: GKI_exception 65524 getbuf: out of buffers
                SaLi_764056

                Hi Sir,

                 

                Does that mean turning ble stack to higher priority a reasonable action if ble-stack is critical to the application ?

                 

                BR,

                Sam

                • 5. Re: GKI_exception 65524 getbuf: out of buffers
                  SaLi_764056

                  Hi Sir,

                   

                  BTW from design aspect if ble stack is important component we should keep ble-stack running even at worst case.

                   

                  That means when out-of-buffer case happens we can tolerate packets drop but not halt/crash system.

                   

                  BR,

                  Sam

                  • 6. Re: GKI_exception 65524 getbuf: out of buffers
                    DaBa_2244756

                    Hi Sam,

                    》That means when out-of-buffer case happens we can tolerate packets drop but not halt/crash system.

                    Yes system not must halt/crash. But maybe it not possible if other task very load or disabled interrupts.

                    I don't known why ble read task have low priority. Application task have default priority higher. So if application

                    task not release cpu, ble read task not working. Ble stack have more tasks. So if you try increase read task priority,

                    then possible problems in internal ble tasks communication. For me was solution set application task priority to 1.

                    BR

                    Darius

                    • 7. Re: GKI_exception 65524 getbuf: out of buffers
                      AxLi_1746341

                      axel.lin_1746341 wrote:

                       

                      The abnormal case:

                      From the Max-used field, you can find it actually run out of all buffers.

                       

                      00:01:01.008856 GKI_create_task func=0x8068651  id=1  name=BTU  stack=0x0  stackSize=6144␍␍␊

                      00:01:01.016856 GKI_create_task func=0x8069b71  id=0  name=HCISU  stack=0x0  stackSize=4096␍␍␊

                      01:58:07.064392 GKI_exception(): Task State Table␍␍␊

                      01:58:07.063856 GKI_exception 65524 getbuf: out of buffers␍␍␊

                      03:04:18.027928 ␍␍␊

                      03:04:18.028928 --- Bluetooth(Pool type: A-App, I-Internal) Buffer summary ---␍␍␊

                      03:04:18.036928 Pool(size,type)   Available   In-use    Total   Max-used␍␍␊

                      03:04:18.043928 --------------------------------------------------------␍␍␊

                      03:04:18.049928 00(  64, A):          12,       4,      16,       5␍␍␊

                      03:04:18.056928 01( 360, A):           6,       0,       6,       6␍␍␊

                      03:04:18.062928 02( 360, A):           6,       0,       6,       6␍␍␊

                      03:04:18.003392 03( 600, A):           2,       0,       2,       2␍␍␊

                       

                       

                      00:02:03.062248 --- Bluetooth(Pool type: A-App, I-Internal) Buffer summary ---␍␍␊

                      00:02:03.004712 Pool(size,type)   Available   In-use    Total   Max-used␍␍␊

                      00:02:03.011712 --------------------------------------------------------␍␍␊

                      00:02:03.018712 00(  64, A):          16,       0,      16,       5␍␍␊

                      00:02:03.024712 01( 360, A):          16,       0,      16,      16␍␍␊

                      00:02:03.031712 02( 360, A):           6,       0,       6,       6␍␍␊

                      00:02:03.037712 03( 600, A):           2,       0,       2,       2␍␍␊

                       

                      Just want to point out increasing the buf_size does not help at all,

                      it still has chance run into GKI_exception 65524 getbuf: out of buffers.

                      • 8. Re: GKI_exception 65524 getbuf: out of buffers
                        AxLi_1746341

                        Below shows a out of buffers happened which does not make sense at all.

                        If the medium buffer full, it should be no problem to take the large buffer.

                        Both large buffer and extra large buffer has free slot for use.

                         

                        00:17:43.016640 --- Bluetooth(Pool type: A-App, I-Internal) Buffer summary ---

                        00:17:43.023640 Pool(size,type)   Available   In-use    Total   Max-used

                        00:17:43.030640 --------------------------------------------------------

                        00:17:43.036640 00(  64, A):          16,       0,      16,       5

                        00:17:43.042640 01( 360, A):          25,       1,      26,      26

                        00:17:43.049640 02( 360, A):           6,       0,       6,       2

                        00:17:43.055640 03( 600, A):           1,       0,       1,       0

                        00:18:18.003032 GKI_exception(): Task State Table␍␍␊

                        00:18:18.008032 GKI_exception 65524 getbuf: out of buffers

                        • 9. Re: GKI_exception 65524 getbuf: out of buffers
                          AxLi_1746341

                          Below shows increasing buffer does not help at all.

                          See, the medium buffer max-used reaches 26 and then start using large buffers. (it just run for less than 4 hours)

                          Make device running longer will find the Max-used increasing.

                           

                           

                          03:54:01.009712 --- Bluetooth(Pool type: A-App, I-Internal) Buffer summary ---␍␍␊

                          03:54:01.016712 Pool(size,type)   Available   In-use    Total   Max-used␍␍␊

                          03:54:01.023712 --------------------------------------------------------␍␍␊

                          03:54:01.029712 00(  64, A):          16,       0,      16,       5␍␍␊

                          03:54:01.036712 01( 360, A):          26,       0,      26,      26␍␍␊

                          03:54:01.042712 02( 360, A):           6,       0,       6,       1␍␍␊

                          03:54:01.048712 03( 600, A):           1,       0,       1,       0␍␍␊