3 Replies Latest reply on Oct 6, 2019 1:36 PM by AlHi_4466391

    kernel warning when running iperf3 UDP test on CYBT-483039-EVAL

    AlHi_4466391

      Hi all,

       

      Evaluating the CYBT-483039-02 module for use in a new design, I have the CYBT-483039-EVAL board plugged into a TI Beagleboard X-15 (running a minimally customized Yocto Warrior OS to add necessary Bluetooth tools) with Bluez5.50


      Set up:

      I followed this blog post to get a Bluetooth PAN network running: https://blind.guru/tag/bluetooth-pan.html under Bluez5.
      I paired with a cheap USB-dongle connected to my PC (Ubuntu 18.04) and have been running iperf3 UDP tests.

      On PC:

      iperf3 -s

      On the BB x-15:

      iperf3 -c <IP-address> -t 120 -u

       

      (Setting the test time to 2 minutes as the error does not occur consistently)

       

      Error encountered:
      (Copied from Syslog - all messages that were printed during the test)

      Sep 10 03:40:39 beagle-x15 systemd[1]: Starting Bluetooth Personal Area Network...
      Sep 10 03:40:39 beagle-x15 bt-pan[358]: DEBUG:root:Using local device (addr: 20:71:9B:19:3E:41): /org/bluez/hci0
      Sep 10 03:40:39 beagle-x15 bt-pan[358]: DEBUG:root:Registered uuid 'nap' with bridge/dev: pan / 20:71:9B:19:3E:41
      Sep 10 03:40:39 beagle-x15 systemd[1]: Started Bluetooth Personal Area Network.
      Sep 10 03:42:16 beagle-x15 systemd-udevd[361]: Using default interface naming scheme 'v240'.
      Sep 10 03:42:16 beagle-x15 kernel: pan: port 1(bnep0) entered blocking state
      Sep 10 03:42:16 beagle-x15 kernel: pan: port 1(bnep0) entered disabled state
      Sep 10 03:42:16 beagle-x15 kernel: device bnep0 entered promiscuous mode
      Sep 10 03:42:16 beagle-x15 systemd-networkd[146]: bnep0: Gained carrier
      Sep 10 03:42:16 beagle-x15 systemd-timesyncd[202]: Network configuration changed, trying to establish connection.
      Sep 10 03:42:16 beagle-x15 kernel: pan: port 1(bnep0) entered blocking state
      Sep 10 03:42:16 beagle-x15 kernel: pan: port 1(bnep0) entered forwarding state
      Sep 10 03:42:16 beagle-x15 systemd-networkd[146]: pan: Gained carrier
      Sep 10 03:42:16 beagle-x15 systemd-networkd[146]: pan: Could not enable IP masquerading: Operation not supported
      Sep 10 03:42:16 beagle-x15 systemd-udevd[361]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
      Sep 10 03:42:16 beagle-x15 systemd-networkd[146]: Failed to determine timezone: No such file or directory
      Sep 10 03:42:16 beagle-x15 systemd-timesyncd[202]: Network configuration changed, trying to establish connection.
      Sep 10 03:42:16 beagle-x15 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): pan: link becomes ready
      Sep 10 03:42:16 beagle-x15 systemd-timesyncd[202]: Network configuration changed, trying to establish connection.
      Sep 10 03:42:17 beagle-x15 systemd-networkd[146]: pan: Gained IPv6LL
      Sep 10 03:42:17 beagle-x15 systemd-networkd[146]: bnep0: Gained IPv6LL
      Sep 10 03:42:17 beagle-x15 systemd-timesyncd[202]: Network configuration changed, trying to establish connection.
      Sep 10 03:42:29 beagle-x15 systemd-networkd[146]: pan: Configured
      Sep 10 03:42:29 beagle-x15 systemd-timesyncd[202]: Network configuration changed, trying to establish connection.
      Sep 10 03:43:50 beagle-x15 systemd[1]: Starting Cleanup of Temporary Directories...
      Sep 10 03:43:50 beagle-x15 systemd[1]: systemd-tmpfiles-clean.service: Succeeded.
      Sep 10 03:43:50 beagle-x15 systemd[1]: Started Cleanup of Temporary Directories.
      Sep 10 03:44:11 beagle-x15 kernel: ------------[ cut here ]------------
      Sep 10 03:44:11 beagle-x15 kernel: WARNING: CPU: 0 PID: 0 at net/sched/sch_generic.c:461 dev_watchdog+0x258/0x25c
      Sep 10 03:44:11 beagle-x15 kernel: NETDEV WATCHDOG: bnep0 (): transmit queue 0 timed out
      Sep 10 03:44:11 beagle-x15 kernel: Modules linked in: bnep hci_uart btbcm cdc_acm xhci_plat_hcd xhci_hcd usbcore pru_rproc irq_pruss_intc pruss dwc3 udc_core usb_common snd_soc_simple_card snd_soc_simple_card_utils ahci_platform libahci_platform libahci snd_soc_omap_hdmi omap_aes_driver omap_sham pruss_soc_bus omap_wdt phy_omap_usb2 libata ti_vpe ti_sc ti_csc dwc3_omap ti_vpdma rtc_omap omap_hdq omap_des des_generic crypto_engine omap_crypto wire rtc_palmas rtc_ds1307 extcon_palmas at24 snd_soc_tlv320aic3x omap_remoteproc remoteproc bridge stp llc sch_fq_codel
      Sep 10 03:44:11 beagle-x15 kernel: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.19.59-g50ceb3c6e7 #1
      Sep 10 03:44:11 beagle-x15 kernel: Hardware name: Generic DRA74X (Flattened Device Tree)
      Sep 10 03:44:11 beagle-x15 kernel: Backtrace: 
      Sep 10 03:44:11 beagle-x15 kernel: [<c020ca34>] (dump_backtrace) from [<c020cd6c>] (show_stack+0x18/0x1c)
      Sep 10 03:44:11 beagle-x15 kernel: r7:c0e5d848 r6:600f0113 r5:00000000 r4:c1250ac0
      Sep 10 03:44:11 beagle-x15 kernel: [<c020cd54>] (show_stack) from [<c0a38280>] (dump_stack+0x90/0xa4)
      Sep 10 03:44:11 beagle-x15 kernel: [<c0a381f0>] (dump_stack) from [<c022deb0>] (__warn+0xdc/0xf8)
      Sep 10 03:44:11 beagle-x15 kernel: r7:c0e5d848 r6:00000009 r5:00000000 r4:c1201cec
      Sep 10 03:44:11 beagle-x15 kernel: [<c022ddd4>] (__warn) from [<c022daf4>] (warn_slowpath_fmt+0x50/0x6c)
      Sep 10 03:44:11 beagle-x15 kernel: r9:ffffffff r8:c1203d00 r7:ec596294 r6:ec596000 r5:c0e5d80c r4:c1204c48
      Sep 10 03:44:11 beagle-x15 kernel: [<c022daa8>] (warn_slowpath_fmt) from [<c08f13d4>] (dev_watchdog+0x258/0x25c)
      Sep 10 03:44:11 beagle-x15 kernel: r3:ec596000 r2:c0e5d80c
      Sep 10 03:44:11 beagle-x15 kernel: r5:ec5962a8 r4:00000000
      Sep 10 03:44:11 beagle-x15 kernel: [<c08f117c>] (dev_watchdog) from [<c02a01a0>] (call_timer_fn+0x2c/0x9c)
      Sep 10 03:44:11 beagle-x15 kernel: r10:00000001 r9:c08f117c r8:00000000 r7:00000200 r6:c08f117c r5:00000101
      Sep 10 03:44:11 beagle-x15 kernel: r4:ffffe000
      Sep 10 03:44:11 beagle-x15 kernel: [<c02a0174>] (call_timer_fn) from [<c02a02a0>] (expire_timers+0x90/0x9c)
      Sep 10 03:44:11 beagle-x15 kernel: r6:c1201da4 r5:eed46540 r4:ec5962a8
      Sep 10 03:44:11 beagle-x15 kernel: [<c02a0210>] (expire_timers) from [<c02a0358>] (run_timer_softirq+0xac/0x1ac)
      Sep 10 03:44:11 beagle-x15 kernel: r9:00000101 r8:c1204c48 r7:c1203d00 r6:c1201da4 r5:eed46540 r4:c1201da4
      Sep 10 03:44:11 beagle-x15 kernel: [<c02a02ac>] (run_timer_softirq) from [<c020215c>] (__do_softirq+0x124/0x28c)
      Sep 10 03:44:11 beagle-x15 kernel: r8:40000001 r7:ffffe000 r6:c1203080 r5:c1203084 r4:00000020
      Sep 10 03:44:11 beagle-x15 kernel: [<c0202038>] (__do_softirq) from [<c0232c90>] (irq_exit+0xd4/0x110)
      Sep 10 03:44:11 beagle-x15 kernel: r10:c10694f0 r9:c1200000 r8:ee80c000 r7:00000001 r6:00000000 r5:00000000
      Sep 10 03:44:11 beagle-x15 kernel: r4:c1069cfc
      Sep 10 03:44:11 beagle-x15 kernel: [<c0232bbc>] (irq_exit) from [<c0287f88>] (__handle_domain_irq+0x68/0xbc)
      Sep 10 03:44:11 beagle-x15 kernel: [<c0287f20>] (__handle_domain_irq) from [<c0559504>] (gic_handle_irq+0x44/0x80)
      Sep 10 03:44:11 beagle-x15 kernel: r9:c1200000 r8:fa213000 r7:c1201eb0 r6:fa212000 r5:fa21200c r4:c1205100
      Sep 10 03:44:11 beagle-x15 kernel: [<c05594c0>] (gic_handle_irq) from [<c02019f8>] (__irq_svc+0x58/0x8c)
      Sep 10 03:44:11 beagle-x15 kernel: Exception stack(0xc1201eb0 to 0xc1201ef8)
      Sep 10 03:44:11 beagle-x15 kernel: 1ea0: 00000000 0009c058 fe600000 00000000
      Sep 10 03:44:11 beagle-x15 kernel: 1ec0: ffffe000 c1204c7c c1204cc4 00000001 00000000 00000000 c10694f0 c1201f0c
      Sep 10 03:44:11 beagle-x15 kernel: 1ee0: c1201eec c1201f00 c0221cfc c0208e94 600f0013 ffffffff
      Sep 10 03:44:11 beagle-x15 kernel: r9:c1200000 r8:00000000 r7:c1201ee4 r6:ffffffff r5:600f0013 r4:c0208e94
      Sep 10 03:44:11 beagle-x15 kernel: [<c0208e6c>] (arch_cpu_idle) from [<c0a5220c>] (default_idle_call+0x30/0x34)
      Sep 10 03:44:11 beagle-x15 kernel: [<c0a521dc>] (default_idle_call) from [<c025a238>] (do_idle+0x20c/0x2b4)
      Sep 10 03:44:11 beagle-x15 kernel: [<c025a02c>] (do_idle) from [<c025a5cc>] (cpu_startup_entry+0x20/0x24)
      Sep 10 03:44:11 beagle-x15 kernel: r10:c104ba38 r9:c12541c0 r8:ffffffff r7:c12541c0 r6:00000000 r5:00000002
      Sep 10 03:44:11 beagle-x15 kernel: r4:000000c6
      Sep 10 03:44:11 beagle-x15 kernel: [<c025a5ac>] (cpu_startup_entry) from [<c0a4c4f4>] (rest_init+0xd0/0xd4)
      Sep 10 03:44:11 beagle-x15 kernel: [<c0a4c424>] (rest_init) from [<c1000dfc>] (start_kernel+0x448/0x470)
      Sep 10 03:44:11 beagle-x15 kernel: r5:00000000 r4:c1254218
      Sep 10 03:44:11 beagle-x15 kernel: [<c10009b4>] (start_kernel) from [<00000000>] ( (null))
      Sep 10 03:44:11 beagle-x15 kernel: ---[ end trace 85e7b9e4ab5c2312 ]---
      Sep 10 03:47:27 beagle-x15 systemd-networkd[146]: bnep0: Lost carrier
      Sep 10 03:47:27 beagle-x15 systemd-timesyncd[202]: Network configuration changed, trying to establish connection.
      Sep 10 03:47:27 beagle-x15 kernel: pan: port 1(bnep0) entered disabled state
      Sep 10 03:47:27 beagle-x15 kernel: device bnep0 left promiscuous mode
      Sep 10 03:47:27 beagle-x15 kernel: pan: port 1(bnep0) entered disabled state
      Sep 10 03:47:27 beagle-x15 systemd-networkd[146]: pan: Lost carrier
      Sep 10 03:47:27 beagle-x15 systemd-timesyncd[202]: Network configuration changed, trying to establish connection.
      Sep 10 03:47:29 beagle-x15 kernel: Bluetooth: hci0: command 0x0c1a tx timeout
      Sep 10 03:47:29 beagle-x15 kernel: Bluetooth: hci0: hardware error 0x00
      Sep 10 03:47:29 beagle-x15 kernel: Bluetooth: hci0: Frame reassembly failed (-84)
      Sep 10 03:47:29 beagle-x15 kernel: Bluetooth: hci0: Frame reassembly failed (-84)
      Sep 10 03:47:29 beagle-x15 kernel: Bluetooth: hci0: Frame reassembly failed (-84)
      Sep 10 03:47:29 beagle-x15 kernel: Bluetooth: hci0: Frame reassembly failed (-84)
      Sep 10 03:47:29 beagle-x15 kernel: Bluetooth: hci0: Frame reassembly failed (-84)
      

       

      After this, the module is unresponsive until power is cycled.

      The module seems to work with TCP tests or at least I have not been able to reproduce the error.

       

      I have tried to reproduce the issue with the CYBT module plugged into my PC (and generic USB dongle on the BB x-15) but have been unable to successfully establish a PAN network to even run a test.

       

      Anyone have advice on why this is happening or how to fix?

        • 1. Re: kernel warning when running iperf3 UDP test on CYBT-483039-EVAL
          AnjanaM_61

          Hi Alistair Higgins

           

          >> I have the CYBT-483039-EVAL board plugged into a TI Beagleboard X-15

          - Is it using the UART transport?

          - including the /RTS and /CTS flowcontrol? (4 lines: TXD, RXD, /RTS, /CTS)

           

           

          lines at the end of log

          Sep 10 03:47:27 beagle-x15 systemd-timesyncd[202]: Network configuration changed, trying to establish connection.

          Sep 10 03:47:29 beagle-x15 kernel: Bluetooth: hci0: command 0x0c1a tx timeout <-- HCI_Write_Scan_Enable

          Sep 10 03:47:29 beagle-x15 kernel: Bluetooth: hci0: hardware error 0x00 <-- 0x00: UART or USB Parsing Error

          Sep 10 03:47:29 beagle-x15 kernel: Bluetooth: hci0: Frame reassembly failed (-84)

           

          Probably the issue is on the UART, baudrare or on the flow control, not the PAN profile related.

          Need to debug the UART communication between CYBT-483039-EVAL and TI Beagleboard X-15.

          Can you please check ? Can you confirm the HCI UART pins are connected properly?

          Check if you are getting a success response for HCI reset command before starting the PAN profile testing.

           

          Thanks,

          Anjana

           

          • 2. Re: kernel warning when running iperf3 UDP test on CYBT-483039-EVAL
            AnjanaM_61

            Hi ,

             

            Did you check the HCI UART communication?

             

            Regards,
            Anjana

            • 3. Re: kernel warning when running iperf3 UDP test on CYBT-483039-EVAL
              AlHi_4466391

              Hi Anjana,

               

              Sorry I was unexpectedly away last week and could not get back to you.

              Need to debug the UART communication between CYBT-483039-EVAL and TI Beagleboard X-15

              I am using the USB port between the Beagleboard and EVAL kit (there is a USB-to-serial chip on the EVAL kit) so I should not have to set the baudrate/flow-control as the USB interface abstracts all that from my control? (I do not see any jumpers or anything to configure this at least).
              I am running "btattach -B /dev/ttyACM0" to attach the Bluetooth ldisc to the virtual serial-port.

               

              I should note that TCP tests work fine (at least I have not reproduced the issue over TCP) and the UDP tests work fine most of the time, they just fail occasionally/sporadically with the above output.

               

              Using btmon and issuing a reset command ("hciconfig hci0 reset") the device appears to be communicating successfully:

              root@beagle-x15:~# btmon
              Bluetooth monitor ver 5.50
              = Note: Linux version 4.19.59-g50ceb3c6e7 (armv7l)                                              0.909735
              = Note: Bluetooth subsystem version 2.22                                                        0.909741
              = New Index: 20:71:9B:19:3E:41 (Primary,UART,hci0)                                      [hci0] 0.909744
              = Open Index: 20:71:9B:19:3E:41                                                          [hci0] 0.909746
              = Index Info: 20:71:9B:19:3E:41 (Cypress Semiconductor Corporation)                      [hci0] 0.909748
              @ MGMT Open: bluetoothd (privileged) version 1.14                                      {0x0001} 0.909751
              @ MGMT Open: btmon (privileged) version 1.14                                          {0x0002} 0.909847
              @ RAW Open: hciconfig (privileged) version 2.22                                      {0x0003} 10.019721
              @ MGMT Event: Class Of Device Changed (0x0007) plen 3                          {0x0002} [hci0] 10.019810
                      Class: 0x000000
                        Major class: Miscellaneous
                        Minor class: 0x00
              @ MGMT Event: Class Of Device Changed (0x0007) plen 3                          {0x0001} [hci0] 10.019810
                      Class: 0x000000
                        Major class: Miscellaneous
                        Minor class: 0x00
              @ MGMT Event: New Settings (0x0006) plen 4                                    {0x0002} [hci0] 10.019872
                      Current settings: 0x00000ad2
                        Connectable
                        Bondable
                        Secure Simple Pairing
                        BR/EDR
                        Low Energy
                        Secure Connections
              @ MGMT Event: New Settings (0x0006) plen 4                                    {0x0001} [hci0] 10.019872
                      Current settings: 0x00000ad2
                        Connectable
                        Bondable
                        Secure Simple Pairing
                        BR/EDR
                        Low Energy
                        Secure Connections
              = Close Index: 20:71:9B:19:3E:41                                                        [hci0] 10.020056
              = Open Index: 20:71:9B:19:3E:41                                                        [hci0] 10.020186
              < HCI Command: Reset (0x03|0x0003) plen 0                                            #1 [hci0] 10.020219
              > HCI Event: Command Complete (0x0e) plen 4                                          #2 [hci0] 10.026075
                    Reset (0x03|0x0003) ncmd 1
                      Status: Success (0x00)
              < HCI Command: Read Local Supported Features (0x04|0x0003) plen 0                    #3 [hci0] 10.026112
              > HCI Event: Command Complete (0x0e) plen 12                                        #4 [hci0] 10.029851
                    Read Local Supported Features (0x04|0x0003) ncmd 1
                      Status: Success (0x00)
                      Features: 0xbf 0xfe 0xcf 0xfe 0xdb 0xff 0x7b 0x87
              <rest of output omitted>
              

               

              Though the issue persists.

               


              Regards,
              Alistair