NRF52840 reprot an error after disconnection

[Hannibalhz]

Dear Nordic Enginneer

         Our customers has a problem when using the NRF52840.

         They want to make a mouse,and now they use LLPM and then they use the gmouse example and the dongle example in NCS.

         They test the communication distance,Dongle is the PCA10056 DK,mouse is their own device.When the mouse and dongle were disconnected at a long distance,the Dongle's RTT printed an error message.There are two type of information printed by LOG:

        Type 1:error code is 0x08,the reason for this situation is connection timeout,so the Dongle and the Mouse can establish a connection again.I think this situation is normal.

        Type 2:error code is 0x3e,this case the Dongle and the Mouse can't establish a connection.

        The customers using the NCS V1.5.1,they only modified one definition of the gmouse program:

        CONFIG_DESKTOP_MOTION_SENSOR_PMW3360_ENABLE=n

        I woule like to know what caused the second situation?The following is the LOG information of the dongle.Please help me analyze

00> [00000000] <inf> event_manager: e: module_state_event module:main state:READY
00> [00000000] <wrn> leds: No effect set
00> [00000000] <wrn> leds: No effect set
00> [00000038] <inf> sdc_hci_driver: SoftDevice Controller build revision:
00> d9 e2 43 71 3b 2d c0 15 55 e1 1d c8 99 75 01 7a |..Cq;-.. U....u.z
00> 62 85 8d 0a |b...
00> [00000051] <inf> power_manager: Activate power manager
00> [00000056] <inf> event_manager: e: module_state_event module:board state:READY
00> [00000059] <inf> event_manager: e: module_state_event module:buttons state:READY
00> [00000062] <inf> event_manager: e: module_state_event module:click_detector state:READY
00> [00000064] <inf> event_manager: e: module_state_event module:leds state:READY
00> [00000067] <inf> event_manager: e: module_state_event module:ble_discovery state:READY
00> [00000070] <inf> event_manager: e: module_state_event module:info state:READY
00> [00000073] <inf> event_manager: e: module_state_event module:usb_state state:READY
00> [00000076] <inf> event_manager: e: led_event led_id:0 effect:0x4aa40
00> [00000220] <inf> bt_hci_core: No ID address. App must call settings_load()
00> [00000221] <inf> ble_state: Bluetooth initialized
00> [00000230] <inf> ble_state: LLPM enabled
00> [00000235] <inf> event_manager: e: module_state_event module:ble_state state:READY
00> [00000251] <inf> event_manager: e: led_ready_event led_id:0 effect:0x4aa40
00> [00000253] <inf> event_manager: e: module_state_event module:ble_conn_params state:READY
00> [00000256] <inf> event_manager: e: module_state_event module:ble_scan state:READY
00> [00000582] <inf> settings_loader: Settings loaded
00> [00000585] <inf> event_manager: e: module_state_event module:hid_forward state:READY
00> [00000588] <inf> event_manager: e: module_state_event module:settings_loader state:READY
00> [00000589] <inf> ble_bond: Device has 1 identities
00> [00000590] <inf> ble_bond: Selected BLE peers
00> [00000595] <inf> event_manager: e: ble_peer_operation_event SELECTED bt_app_id=0 bt_stack_id=0
00> [00000597] <inf> event_manager: e: module_state_event module:ble_bond state:READY
00> [00000607] <inf> ble_scan: Address filter added F1:7F:A1:3F:AB:CA (random)
00> [00000608] <inf> ble_scan: Device name filters added
00> [00009145] <inf> ble_scan: Scan started
00> [00009149] <inf> event_manager: e: led_event led_id:1 effect:0x4aa10
00> [00009151] <inf> event_manager: e: ble_peer_search_event active
00> [00009156] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [00009159] <inf> event_manager: e: led_ready_event led_id:1 effect:0x4aa10
00> [00373365] <inf> ble_scan: Filters matched. F1:7F:A1:3F:AB:CA (random) connectable
00> [00373394] <inf> ble_scan: Connecting done
00> [00375516] <inf> ble_state: Setting TX power to: 0
00> [00375525] <inf> ble_state: TX power returned by command: 0
00> [00375526] <inf> ble_state: Connected to F1:7F:A1:3F:AB:CA (random)
00> [00375539] <inf> event_manager: e: ble_peer_event id=0x20002e48 CONNECTED
00> [00375543] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [00384081] <inf> ble_state: Security with F1:7F:A1:3F:AB:CA (random) level 2
00> [00384089] <inf> event_manager: e: ble_peer_event id=0x20002e48 SECURED
00> [00384095] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [00384584] <inf> ble_state: MTU exchange done
00> [00388500] <inf> ble_discovery: LLPM supported
00> [00392683] <inf> ble_discovery: HW ID: 9f8c3c06288b809f
00> [00395874] <inf> ble_discovery: VID: 1915 PID: 52de
00> [00398577] <inf> ble_discovery: HIDS discovery procedure succeeded
00> [00398579] <inf> event_manager: e: ble_discovery_complete_event
00> [00398579] <inf> hid_forward: Subscriber id found (0)
00> [00398592] <inf> hid_forward: Peripheral 0x20002888 registered and linked to 0x20003be4
00> [00398602] <inf> ble_conn_params: Conn params for peer: 0x20002e48 set: LLPM, latency: 0
00> [00400309] <inf> event_manager: e: ble_peer_conn_params_event peer=0x20002e48 min=d01 max=d01 lat=0 timeout=400 (updated)
00> [00400607] <inf> hid_forward: Subscriber to rep id:1
00> [00412580] <inf> event_manager: e: ble_peer_conn_params_event peer=0x20002e48 min=6 max=6 lat=99 timeout=400 (required)
00> [00412580] <inf> ble_conn_params: Request to update conn: 0x20002e48 latency to: 99
00> [00412606] <inf> ble_conn_params: Conn params for peer: 0x20002e48 set: LLPM, latency: 99
00> [00414114] <inf> event_manager: e: ble_peer_conn_params_event peer=0x20002e48 min=d01 max=d01 lat=99 timeout=400 (updated)
00> [00414151] <inf> event_manager: e: ble_peer_conn_params_event peer=0x20002e48 min=6 max=6 lat=0 timeout=400 (required)
00> [00414153] <inf> ble_conn_params: Request to update conn: 0x20002e48 latency to: 0
00> [00414179] <inf> ble_conn_params: Conn params for peer: 0x20002e48 set: LLPM, latency: 0
00> [00418931] <inf> event_manager: e: ble_peer_conn_params_event peer=0x20002e48 min=d01 max=d01 lat=0 timeout=400 (updated)
00> [00558625] <wrn> ble_scan: Active scan already disabled
00> [00558635] <inf> ble_scan: Device name filters added
00> [00558685] <inf> ble_scan: Scan started
00> [00558688] <inf> event_manager: e: ble_peer_search_event inactive
00> [00558691] <inf> event_manager: e: ble_peer_search_event active
00> [00558700] <inf> event_manager: e: led_event led_id:1 effect:0x4aa18
00> [00558703] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [01323068] <inf> ble_state: Disconnected from F1:7F:A1:3F:AB:CA (random) (reason 8)
00> [01323071] <inf> event_manager: e: ble_peer_event id=0x20002e48 DISCONNECTED
00> [01323072] <inf> hid_forward: Peripheral 0x20002888 disconnected
00> [01323077] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [01323597] <inf> ble_scan: Scan stopped
00> [01323606] <inf> ble_scan: Address filter added F1:7F:A1:3F:AB:CA (random)
00> [01323607] <inf> ble_scan: Device name filters added
00> [01323628] <inf> ble_scan: Scan started
00> [01323631] <inf> event_manager: e: ble_peer_search_event inactive
00> [01323634] <inf> event_manager: e: ble_peer_search_event active
00> [01323638] <inf> event_manager: e: led_event led_id:1 effect:0x4aa10
00> [01323641] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [01324518] <inf> ble_scan: Filters matched. F1:7F:A1:3F:AB:CA (random) connectable
00> [01324547] <inf> ble_scan: Connecting done
00> [01325557] <inf> ble_state: Setting TX power to: 0
00> [01325566] <inf> ble_state: TX power returned by command: 0
00> [01325567] <inf> ble_state: Connected to F1:7F:A1:3F:AB:CA (random)
00> [01325580] <inf> event_manager: e: ble_peer_event id=0x20002e48 CONNECTED
00> [01325584] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [01327618] <inf> ble_state: Security with F1:7F:A1:3F:AB:CA (random) level 2
00> [01327627] <inf> event_manager: e: ble_peer_event id=0x20002e48 SECURED
00> [01327633] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [01328599] <inf> ble_state: MTU exchange done
00> [01332772] <inf> ble_discovery: LLPM supported
00> [01337446] <inf> ble_discovery: HW ID: 9f8c3c06288b809f
00> [01339900] <inf> ble_discovery: VID: 1915 PID: 52de
00> [01342603] <inf> ble_discovery: HIDS discovery procedure succeeded
00> [01342605] <inf> event_manager: e: ble_discovery_complete_event
00> [01342605] <inf> hid_forward: Subscriber id found (0)
00> [01342618] <inf> hid_forward: Peripheral 0x20002888 registered and linked to 0x20003be4
00> [01342628] <inf> ble_conn_params: Conn params for peer: 0x20002e48 set: LLPM, latency: 0
00> [01344327] <inf> event_manager: e: ble_peer_conn_params_event peer=0x20002e48 min=d01 max=d01 lat=0 timeout=400 (updated)
00> [01344764] <inf> hid_forward: Subscriber to rep id:1
00> [01357654] <inf> event_manager: e: ble_peer_conn_params_event peer=0x20002e48 min=6 max=6 lat=99 timeout=400 (required)
00> [01357655] <inf> ble_conn_params: Request to update conn: 0x20002e48 latency to: 99
00> [01357680] <inf> ble_conn_params: Conn params for peer: 0x20002e48 set: LLPM, latency: 99
00> [01359188] <inf> event_manager: e: ble_peer_conn_params_event peer=0x20002e48 min=d01 max=d01 lat=99 timeout=400 (updated)
00> [01359227] <inf> event_manager: e: ble_peer_conn_params_event peer=0x20002e48 min=6 max=6 lat=0 timeout=400 (required)
00> [01359228] <inf> ble_conn_params: Request to update conn: 0x20002e48 latency to: 0
00> [01359254] <inf> ble_conn_params: Conn params for peer: 0x20002e48 set: LLPM, latency: 0
00> [01364005] <inf> event_manager: e: ble_peer_conn_params_event peer=0x20002e48 min=d01 max=d01 lat=0 timeout=400 (updated)
00> [01502669] <wrn> ble_scan: Active scan already disabled
00> [01502673] <inf> ble_scan: Device name filters added
00> [01502714] <inf> ble_scan: Scan started
00> [01502717] <inf> event_manager: e: ble_peer_search_event inactive
00> [01502725] <inf> event_manager: e: ble_peer_search_event active
00> [01502737] <inf> event_manager: e: led_event led_id:1 effect:0x4aa18
00> [01502740] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [02211683] <inf> ble_state: Disconnected from F1:7F:A1:3F:AB:CA (random) (reason 8)
00> [02211687] <inf> event_manager: e: ble_peer_event id=0x20002e48 DISCONNECTED
00> [02211688] <inf> hid_forward: Peripheral 0x20002888 disconnected
00> [02211693] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [02212203] <inf> ble_scan: Scan stopped
00> [02212212] <inf> ble_scan: Address filter added F1:7F:A1:3F:AB:CA (random)
00> [02212213] <inf> ble_scan: Device name filters added
00> [02212234] <inf> ble_scan: Scan started
00> [02212237] <inf> event_manager: e: ble_peer_search_event inactive
00> [02212239] <inf> event_manager: e: ble_peer_search_event active
00> [02212243] <inf> event_manager: e: led_event led_id:1 effect:0x4aa10
00> [02212247] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [02307309] <inf> ble_scan: Filters matched. F1:7F:A1:3F:AB:CA (random) connectable
00> [02307338] <inf> ble_scan: Connecting done
00> [02308478] <inf> ble_state: Setting TX power to: 0
00> [02308487] <inf> ble_state: TX power returned by command: 0
00> [02308488] <inf> ble_state: Connected to F1:7F:A1:3F:AB:CA (random)
00> [02308501] <inf> event_manager: e: ble_peer_event id=0x20002e48 CONNECTED
00> [02308505] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [02310053] <inf> ble_state: Disconnected from F1:7F:A1:3F:AB:CA (random) (reason 62)
00> [02310056] <inf> event_manager: e: ble_peer_event id=0x20002e48 DISCONNECTED
00> [02310061] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [02310561] <wrn> ble_scan: Active scan already disabled
00> [02310571] <inf> ble_scan: Address filter added F1:7F:A1:3F:AB:CA (random)
00> [02310572] <inf> ble_scan: Device name filters added
00> [02310593] <inf> ble_scan: Scan started
00> [02310596] <inf> event_manager: e: ble_peer_search_event inactive
00> [02310598] <inf> event_manager: e: ble_peer_search_event active
00> [02310602] <inf> event_manager: e: led_event led_id:1 effect:0x4aa10
00> [02310605] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [02329108] <inf> ble_scan: Filters matched. F1:7F:A1:3F:AB:CA (random) connectable
00> [02329137] <inf> ble_scan: Connecting done
00> [02353155] <inf> ble_state: Setting TX power to: 0
00> [02353164] <inf> ble_state: TX power returned by command: 0
00> [02353165] <inf> ble_state: Connected to F1:7F:A1:3F:AB:CA (random)
00> [02353178] <inf> event_manager: e: ble_peer_event id=0x20002e48 CONNECTED
00> [02353182] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [02354707] <inf> ble_state: Disconnected from F1:7F:A1:3F:AB:CA (random) (reason 62)
00> [02354711] <inf> event_manager: e: ble_peer_event id=0x20002e48 DISCONNECTED
00> [02354715] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [02355201] <wrn> ble_scan: Active scan already disabled
00> [02355211] <inf> ble_scan: Address filter added F1:7F:A1:3F:AB:CA (random)
00> [02355212] <inf> ble_scan: Device name filters added
00> [02355233] <inf> ble_scan: Scan started
00> [02355236] <inf> event_manager: e: ble_peer_search_event inactive
00> [02355238] <inf> event_manager: e: ble_peer_search_event active
00> [02355242] <inf> event_manager: e: led_event led_id:1 effect:0x4aa10
00> [02355245] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20
00> [06214241] <inf> power_manager: System power down
00> [06214243] <inf> event_manager: e: power_down_event
00> [06214249] <inf> power_manager: Power down the board
00> [06214249] <wrn> power_manager: System suspended
00> [06214251] <inf> event_manager: e: module_state_event module:buttons state:STANDBY
00> [06214254] <inf> event_manager: e: module_state_event module:board state:OFF
00> [06214256] <inf> event_manager: e: module_state_event module:click_detector state:OFF
00> [06214259] <inf> event_manager: e: module_state_event module:leds state:OFF
00> [06214261] <inf> event_manager: e: module_state_event module:ble_bond state:OFF

[Kenneth]

0x3e

This is a common error code also ("failed to establish connection"), it simply means that the central sent a connection request packet, but the connection request packet not received by the peripheral. The packet loss may happen due to interference, it's marginally out of range, other central roles devices trying to scan the peer etc. 

So both error codes (disconnect reasons) are normal.

Best regards,
Kenneth

[Hannibalhz]

Dear Kenneth

        Thank you for your reply! I have  a one more question I would like to ask you.Please tell me why the Mouse and the Dongle can't connect again after the error 0x03is generated?Only by restarting the two deveice can the connection be re-established.

       Looking forward to your reply~

[Hannibalhz]

Dear Kenneth

  Our customer once again asked why the connection could not be established again. Could you please give me a little help?

  Looking forward to your reply.Thanks you.

[Kenneth]

Have they written code to ensure that the dongle will start to scan again when receiving the disconnect event?

Also, the same for the peripheral, does it start to advertise again after disconnect event?

I suspect they may go to sleep on disconnect.

Kenneth

[Hannibalhz]

 Dear Kenneth

  Today  I used two 52840DKs. The burning program was as I described before. I didn’t modify any programs, only the configuration. What I saw seemed to be a problem with DONGLE. As long as DONGLE was powered off and restarted, the mouse and dongle can reconnect. The following is the information printed by RTT after disconnection. The dongle starts to scan, but it seems to enter some abnormal state after the connection fails.

00> [03057248] <inf> ble_scan: Scan started

00> [03057251] <inf> event_manager: e: ble_peer_search_event inactive

00> [03057253] <inf> event_manager: e: ble_peer_search_event active

00> [03057257] <inf> event_manager: e: led_event led_id:1 effect:0x4aa10

00> [03057260] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20

00> [03073621] <inf> ble_scan: Filters matched. F1:7F:A1:3F:AB:CA (random) connectable

00> [03073650] <inf> ble_scan: Connecting done

00> [03092138] <inf> ble_state: Setting TX power to: 0

00> [03092147] <inf> ble_state: TX power returned by command: 0

00> [03092148] <inf> ble_state: Connected to F1:7F:A1:3F:AB:CA (random)

00> [03092161] <inf> event_manager: e: ble_peer_event id=0x20002e48 CONNECTED

00> [03092167] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20

00> [03093567] <inf> ble_state: Disconnected from F1:7F:A1:3F:AB:CA (random) (reason 62)

00> [03093570] <inf> event_manager: e: ble_peer_event id=0x20002e48 DISCONNECTED

00> [03093575] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20

00> [03094081] <wrn> ble_scan: Active scan already disabled

00> [03094091] <inf> ble_scan: Address filter added F1:7F:A1:3F:AB:CA (random)

00> [03094112] <inf> ble_scan: Scan started

00> [03094115] <inf> event_manager: e: ble_peer_search_event inactive

00> [03094117] <inf> event_manager: e: ble_peer_search_event active

00> [03094121] <inf> event_manager: e: led_event led_id:1 effect:0x4aa10

00> [03094124] <inf> event_manager: e: led_event led_id:1 effect:0x4aa20

According to the LOG information, it seems that an abnormality occurred during the last scan.

I have already suggested that they enable Dongle watchdog. May I ask if there is any better suggestion for this issue. Our client is very anxious, so please help analyze it as soon as possible.

Looking forward to your reply.Thanks you.

[Kenneth]

Let me ask a bit internally if someone have a suggestion.

Edit: One thing you can try in the meantime, in scan_init() change from BT_LE_SCAN_OPT_FILTER_DUPLICATE to BT_LE_SCAN_OPT_NONE.

Best regards,
Kenneth