Zephyr IPSP sample crashes and ble controller crashes (IPv6 over BLE)


Priyanka
 

Hello

My test set up for IPv6 over BLE is following :

At one end : Two boards frdm-kw41z and frdm-k64f are stacked together.
kw41z (flashed with hci_blackbox firmware) is ble controller with k64f as ble host (flashed with zephyr sample IPSP).

At the other end: Second kw41z (flashed with hci_blackbox firmware) is ble controller attached to Linux host. 


[Kw41z  (ble controller)+ k64f (zephyr IPSP)] <---------->[Kw41z (ble controller)+Linux host]

Issue with testing IPv6 over BLE :

Once the BLE connection is established, within few seconds BLE controller gets disconnected.
Either zephyr (recent master branch) crashes or BLE controller crashes or both. Often it is BLE controller that gets disconnected within few seconds.
Restarting zephyr might enable establishing the connection once again, but then ble controller goes down immediately.

After that, I should disconnect the boards and connect again (via usb connection) in order to set up the ble connection again.

While on Zephyr side, it always prints connection handle 32
On Linux side, the first time connection handle is 32, afterwards it is different (handle 65, 128 etc.,) as shown with "hcitool conn".
btmon log shows for specific handle : remote user terminated connection or connection terminated by local host

On Linux PC
--------------
$ sudo hciattach ttyACMx any 115200 noflow sleep
Device setup complete

$ sudo hcitool conn

Connections:

< LE 00:04:9F:00:00:15 handle 32 state 1 lm MASTER


$ sudo hcitool conn

Connections:

< LE 00:04:9F:00:00:15 handle 65 state 8 lm MASTER

$ sudo hcitool conn

Connections:


$ sudo hcitool lescan

LE Scan ...

00:04:9F:00:00:15 (unknown)

00:04:9F:00:00:15 Test IPSP node

04:52:C7:64:6C:65 (unknown)


$ sudo hcitool conn

Connections:

< LE 00:04:9F:00:00:15 handle 96 state 1 lm MASTER

$ sudo hcitool conn

Connections:

$ sudo hcitool conn

Connections:

< LE 00:04:9F:00:00:15 handle 128 state 1 lm MASTER

$ sudo hcitool conn

Connections:



Zephyr (IPSP)
--------------------
During that very short span of connection, ping does not pass, there is a ping time out and then ble controller goes down.

And it prints error

[bt] [ERR] read_payload: Not enough space in buffer


net> iface

Interface 0x2000a020 (Bluetooth)
================================
Link addr : 00:04:9F:00:00:15
MTU       : 1280
IPv6 unicast addresses (max 3):
        2001:db8::1 manual preferred infinite
        fe80::4:9fff:fe00:15 autoconf preferred infinite
IPv6 multicast addresses (max 2):
        ff84::2
        ff02::1
IPv6 prefixes (max 2):
        <none>
IPv6 hop limit           : 64
IPv6 base reachable time : 30000
IPv6 reachable time      : 9178
IPv6 retransmit timer    : 0
net> ping 2001:db8::2
Sent a ping to 2001:db8::2
[bt] [DBG] bt_l2cap_chan_send: (0x20001210) chan 0x20009bcc buf 0x20006db4 len 57
[bt] [DBG] l2cap_chan_create_seg: (0x20001210) ch 0x20009bcc seg 0x20006bf8 len 59
[bt] [DBG] l2cap_chan_le_send: (0x20001210) ch 0x20009bcc cid 0x0040 len 59 credits 3
[bt] [DBG] bt_l2cap_send_cb: (0x20001210) conn 0x200008d4 cid 64 len 59
[bt] [DBG] bt_conn_send_cb: (0x20001210) conn handle 32 buf len 63 cb 0x00000000
[bt] [DBG] l2cap_chan_le_send_sdu: (0x20001210) ch 0x20009bcc cid 0x0040 sent 57 total_len 57
[bt] [DBG] bt_conn_process_tx: (0x200006f8) conn 0x200008d4
[bt] [DBG] send_buf: (0x200006f8) conn 0x200008d4 buf 0x20006bf8 len 63
[bt] [DBG] send_frag: (0x200006f8) conn 0x200008d4 buf 0x20006bf8 len 63 flags 0x00
[bt] [DBG] bt_conn_notify_tx: (0x200006f8) conn 0x200008d4
[bt] [DBG] add_pending_tx: (0x200006f8) conn 0x200008d4 cb 0x00000000
[bt] [DBG] bt_conn_prepare_events: (0x200006f8)
[bt] [DBG] bt_conn_prepare_events: (0x200006f8) Adding conn 0x200008d4 to poll list
Ping timeout

btmon log shows for specific handle : remote user terminated connection or connection terminated by local host

$ sudo btmon

< HCI Command: Disconnect (0x01|0x0006) plen 3                                                                             [hci0] 56.603853
        Handle: 32
        Reason: Remote User Terminated Connection (0x13)
> HCI Event: Command Status (0x0f) plen 4                                                                                  [hci0] 56.605669
      Disconnect (0x01|0x0006) ncmd 1
        Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                     [hci0] 56.623140
        Num handles: 1
        Handle: 32
        Count: 0
> HCI Event: Disconnect Complete (0x05) plen 4                                                                             [hci0] 56.623895
        Status: Success (0x00)
        Handle: 32
        Reason: Connection Terminated By Local Host (0x16)
@ Device Disconnected: 00:04:9F:00:00:15 (1) reason 2



$ sudo btmon
Bluetooth monitor ver 5.37
= New Index: 00:60:37:00:00:16 (BR/EDR,UART,hci0)                                                                           [hci0] 0.420344
= Open Index: 00:60:37:00:00:16                                                                                             [hci0] 0.420346
= Index Info: 00:60:37:00:00:16 (NXP Semiconductors (formerly Philips Semiconductors))                                      [hci0] 0.420347
> HCI Event: LE Meta Event (0x3e) plen 19                                                                                  [hci0] 25.087469
      LE Connection Complete (0x01)
        Status: Success (0x00)
        Handle: 32
        Role: Master (0x00)
        Peer address type: Public (0x00)
        Peer address: 00:04:9F:00:00:15 (Freescale Semiconductor)
        Connection interval: 18.75 msec (0x000f)
        Connection latency: 0.00 msec (0x0000)
        Supervision timeout: 32000 msec (0x0c80)
        Master clock accuracy: 0x00
< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2                                                           [hci0] 25.087749
        Handle: 32
@ Device Connected: 00:04:9F:00:00:15 (1) flags 0x0000
> HCI Event: Command Status (0x0f) plen 4                                                                                  [hci0] 25.090858
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)
> HCI Event: LE Meta Event (0x3e) plen 12                                                                                  [hci0] 25.160087
      LE Read Remote Used Features (0x04)
        Status: Success (0x00)
        Handle: 32
        Features: 0xff 0x00 0x00 0x00 0x00 0x00 0x00 0x00
          LE Encryption
          Connection Parameter Request Procedure
          Extended Reject Indication
          Slave-initiated Features Exchange
          LE Ping
          LE Data Packet Length Extension
          LL Privacy
          Extended Scanner Filter Policies
< ACL Data TX: Handle 32 flags 0x00 dlen 7                                                                                 [hci0] 25.160299
      ATT: Exchange MTU Request (0x02) len 2
        Client RX MTU: 517
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                     [hci0] 25.197003
        Num handles: 1
        Handle: 32
        Count: 1
> HCI Event: LE Meta Event (0x3e) plen 11                                                                                  [hci0] 25.216210
      LE Data Length Change (0x07)
        Handle: 32
        Max TX octets: 251
        Max TX time: 2120
        Max RX octets: 251
        Max RX time: 2120
> ACL Data RX: Handle 32 flags 0x02 dlen 7                                                                                 [hci0] 25.291092
      ATT: Exchange MTU Response (0x03) len 2
        Server RX MTU: 65
< ACL Data TX: Handle 32 flags 0x00 dlen 11                                                                                [hci0] 25.291176
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                     [hci0] 25.309459
        Num handles: 1
        Handle: 32
        Count: 1
< HCI Command: LE Create Connection (0x08|0x000d) plen 25                                                                  [hci0] 56.599500
        Scan interval: 2.500 msec (0x0004)
        Scan window: 2.500 msec (0x0004)
        Filter policy: White list is not used (0x00)
        Peer address type: Public (0x00)
        Peer address: 00:04:9F:00:00:15 (Freescale Semiconductor)
        Own address type: Public (0x00)
        Min connection interval: 18.75 msec (0x000f)
        Max connection interval: 18.75 msec (0x000f)
        Connection latency: 0x0000
        Supervision timeout: 32000 msec (0x0c80)
        Min connection length: 0.625 msec (0x0001)
        Max connection length: 0.625 msec (0x0001)
> HCI Event: Command Status (0x0f) plen 4                                                                                  [hci0] 56.603808
      LE Create Connection (0x08|0x000d) ncmd 1
        Status: Success (0x00)
< HCI Command: Disconnect (0x01|0x0006) plen 3                                                                             [hci0] 56.603853
        Handle: 32
        Reason: Remote User Terminated Connection (0x13)
> HCI Event: Command Status (0x0f) plen 4                                                                                  [hci0] 56.605669
      Disconnect (0x01|0x0006) ncmd 1
        Status: Success (0x00)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                     [hci0] 56.623140
        Num handles: 1
        Handle: 32
        Count: 0
> HCI Event: Disconnect Complete (0x05) plen 4                                                                             [hci0] 56.623895
        Status: Success (0x00)
        Handle: 32
        Reason: Connection Terminated By Local Host (0x16)
@ Device Disconnected: 00:04:9F:00:00:15 (1) reason 2

> HCI Event: Disconnect Complete (0x05) plen 4                                                                            [hci0] 495.817382
        Status: Success (0x00)
        Handle: 96
        Reason: Connection Terminated By Local Host (0x16)
@ Device Disconnected: 00:04:9F:00:00:15 (1) reason 2


< HCI Command: LE Read Remote Used Features (0x08|0x0016) plen 2                                                          [hci0] 559.455648
        Handle: 128
@ Device Connected: 00:04:9F:00:00:15 (1) flags 0x0000
> HCI Event: Command Status (0x0f) plen 4                                                                                 [hci0] 559.458269
      LE Read Remote Used Features (0x08|0x0016) ncmd 1
        Status: Success (0x00)

> HCI Event: LE Meta Event (0x3e) plen 12                                                                                 [hci0] 559.552125
      LE Read Remote Used Features (0x04)
        Status: Success (0x00)
        Handle: 128
        Features: 0xff 0x00 0x00 0x00 0x00 0x00 0x00 0x00
          LE Encryption
          Connection Parameter Request Procedure
          Extended Reject Indication
          Slave-initiated Features Exchange
          LE Ping
          LE Data Packet Length Extension
          LL Privacy
          Extended Scanner Filter Policies
< ACL Data TX: Handle 128 flags 0x00 dlen 7                                                                               [hci0] 559.552334
      ATT: Exchange MTU Request (0x02) len 2
        Client RX MTU: 517
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                    [hci0] 559.589004
        Num handles: 1
        Handle: 128
        Count: 1
> HCI Event: LE Meta Event (0x3e) plen 11                                                                                 [hci0] 559.608138
      LE Data Length Change (0x07)
        Handle: 128
        Max TX octets: 251
        Max TX time: 2120
        Max RX octets: 251
        Max RX time: 2120
> ACL Data RX: Handle 128 flags 0x02 dlen 7                                                                               [hci0] 559.683143
      ATT: Exchange MTU Response (0x03) len 2
        Server RX MTU: 65
< ACL Data TX: Handle 128 flags 0x00 dlen 11                                                                              [hci0] 559.683325
      ATT: Read By Group Type Request (0x10) len 6
        Handle range: 0x0001-0xffff
        Attribute group type: Primary Service (0x2800)
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                    [hci0] 559.701758
        Num handles: 1
        Handle: 128
        Count: 1
> HCI Event: LE Meta Event (0x3e) plen 11                                                                                 [hci0] 564.727345
      LE Remote Connection Parameter Request (0x06)
        Handle: 128
        Min connection interval: 30.00 msec (0x0018)
        Max connection interval: 50.00 msec (0x0028)
        Connection latency: 0x0000
        Supervision timeout: 32000 msec (0x0c80)
< HCI Command: LE Remote Connection Parameter Request Reply (0x08|0x0020) plen 14                                         [hci0] 564.727418
        Handle: 128
        Min connection interval: 30.00 msec (0x0018)
        Max connection interval: 50.00 msec (0x0028)
        Connection latency: 0x0000
        Supervision timeout: 32000 msec (0x0c80)
        Min connection length: 0.000 msec (0x0000)
        Max connection length: 0.000 msec (0x0000)
@ New Conn Param: 00:04:9F:00:00:15 (1) hint 1 min 0x0018 max 0x0028 latency 0x0000 timeout 0x0c80
> HCI Event: Command Complete (0x0e) plen 6                                                                               [hci0] 564.731202
      LE Remote Connection Parameter Request Reply (0x08|0x0020) ncmd 1
        Status: Success (0x00)
        Handle: 128
> HCI Event: LE Meta Event (0x3e) plen 10                                                                                 [hci0] 564.971598
      LE Connection Update Complete (0x03)
        Status: Success (0x00)
        Handle: 128
        Connection interval: 30.00 msec (0x0018)
        Connection latency: 0.00 msec (0x0000)
        Supervision timeout: 32000 msec (0x0c80)
< ACL Data TX: Handle 128 flags 0x00 dlen 18                                                                              [hci0] 577.871547
      LE L2CAP: LE Connection Request (0x14) ident 1 len 10
        PSM: 35 (0x0023)
        Source CID: 64
        MTU: 1280
        MPS: 230
        Credits: 10
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                    [hci0] 577.902129
        Num handles: 1
        Handle: 128
        Count: 1
> ACL Data RX: Handle 128 flags 0x02 dlen 18                                                                              [hci0] 578.113503
      LE L2CAP: LE Connection Response (0x15) ident 1 len 10
        Destination CID: 64
        MTU: 1280
        MPS: 65
        Credits: 20
        Result: Connection successful (0x0000)
< ACL Data TX: Handle 128 flags 0x00 dlen 46                                                                              [hci0] 578.119173
      Channel: 64 len 42 [PSM 35 mode 0] {chan 2}
        28 00 79 4b 00 16 3a 00 05 02 00 00 01 00 8f 00  (.yK..:.........
        6f 74 00 00 00 01 04 00 00 00 ff 02 00 00 00 00  ot..............
        00 00 00 00 00 01 ff 00 00 16                    ..........      
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                    [hci0] 578.142511
        Num handles: 1
        Handle: 128
        Count: 1
< ACL Data TX: Handle 128 flags 0x00 dlen 50                                                                              [hci0] 578.211240
      Channel: 64 len 46 [PSM 35 mode 0] {chan 2}
        2c 00 7b 3b 3a 01 88 00 b2 32 20 00 00 00 fe 80  ,.{;:....2 .....
        00 00 00 00 00 00 02 60 37 ff fe 00 00 16 02 02  .......`7.......
        00 60 37 ff fe 00 00 16 00 00 00 00 00 00        .`7...........  
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                    [hci0] 578.232753
        Num handles: 1
        Handle: 128
        Count: 1
> ACL Data RX: Handle 128 flags 0x02 dlen 39                                                                              [hci0] 578.236748
      Channel: 64 len 35 [PSM 35 mode 0] {chan 2}
        21 00 7b 49 3a 02 01 ff 00 00 15 87 00 0c 2c 2a  !.{I:.........,*
        52 a7 7a fe 80 00 00 00 00 00 00 00 04 9f ff fe  R.z.............
        00 00 15                                         ...             
< ACL Data TX: Handle 128 flags 0x00 dlen 39                                                                              [hci0] 578.263150
      Channel: 64 len 35 [PSM 35 mode 0] {chan 2}
        21 00 7b 49 3a 02 01 ff 00 00 16 87 00 43 9b 00  !.{I:........C..
        00 00 00 fe 80 00 00 00 00 00 00 02 60 37 ff fe  ............`7..
        00 00 16                                         ...             
> HCI Event: Number of Completed Packets (0x13) plen 5                                                                    [hci0] 578.292505
        Num handles: 1
        Handle: 128
        Count: 1


--------------------------------------------------------

samples/bluetooth/ipsp$ prj.conf

CONFIG_BT=y
CONFIG_BT_DEBUG_LOG=y
CONFIG_BT_SMP=y
CONFIG_BT_PERIPHERAL=y
CONFIG_BT_L2CAP_DYNAMIC_CHANNEL=y
CONFIG_BT_DEVICE_NAME="Test IPSP node"
CONFIG_NETWORKING=y
CONFIG_NET_IPV6=y
CONFIG_NET_IPV4=n
CONFIG_NET_UDP=y
CONFIG_NET_TCP=y
CONFIG_TEST_RANDOM_GENERATOR=y
CONFIG_NET_LOG=y
CONFIG_NET_L2_BT=y
CONFIG_NET_DEBUG_L2_BT=y
CONFIG_SYS_LOG_SHOW_COLOR=y
CONFIG_INIT_STACKS=y
CONFIG_NET_STATISTICS=y
CONFIG_NET_PKT_RX_COUNT=10
CONFIG_NET_PKT_TX_COUNT=10
CONFIG_NET_BUF_RX_COUNT=20
CONFIG_NET_BUF_TX_COUNT=20
CONFIG_NET_IF_UNICAST_IPV6_ADDR_COUNT=3
CONFIG_NET_IF_MCAST_IPV6_ADDR_COUNT=2
CONFIG_NET_MAX_CONTEXTS=6

CONFIG_NET_SHELL=y
CONFIG_BT_SHELL=y

CONFIG_NET_APP_SETTINGS=y
CONFIG_NET_APP_MY_IPV6_ADDR="2001:db8::1"
CONFIG_NET_APP_PEER_IPV6_ADDR="2001:db8::2"
CONFIG_NET_APP_BT_NODE=y

CONFIG_NET_L2_ETHERNET=n
CONFIG_ETH_MCUX=n
CONFIG_ETH_MCUX_0=n

#CONFIG_BT_DEBUG_HCI_DRIVER=y
#CONFIG_BT_DEBUG_HCI_CORE=y

CONFIG_BT_PRIVACY=n
#CONFIG_BT_DEBUG=y
#CONFIG_BT_DEBUG_HCI_CORE=n
CONFIG_BT_DEBUG_CONN=y
CONFIG_BT_DEBUG_KEYS=y
CONFIG_BT_DEBUG_L2CAP=y
CONFIG_BT_DEBUG_SMP=y
CONFIG_BT_DEBUG_SDP=y


Thanks

Priyanka