[MYNEWT-756] mpstats (on nrf51) hangs indefinately

• Type: Bug
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: v1_1_0_rel
• Component/s: Newt
• Security Level: Public (Viewable by anyone)
• Assignee: Christopher Collins
• Reporter: Jacob Rosenthal
• Created: 13/May/17 02:01
• Updated: 26/Jun/17 21:44
• Resolved: 26/Jun/17 21:44

Description

I believe core is failing before sending the last packet, as neither newtmgr or node-newtmgr receives that packet.

Jacobs-MacBook-Air:newtmgr jacobrosenthal$ GODEBUG=cgocheck=0 newtmgr mpstats -cnimble_bleprph -t -ldebug
2017/05/11 22:28:46 [DEBUG] BLE Connection devaddr:[]
2017/05/11 22:28:46 [DEBUG] State:PoweredOn
2017/05/11 22:28:46 [DEBUG] scanning...
2017/05/11 22:28:46 [DEBUG] Peripheral Discovered: , Address:[0 0 0 0 0 0] Address Type:0
2017/05/11 22:28:47 Unhandled event: xpc.Dict{"kCBMsgId":53, "kCBMsgArgs":xpc.Dict{"kCBMsgArgDeviceUUID":xpc.UUID

{0x2f, 0xd, 0xcb, 0x60, 0xf, 0x3e, 0x47, 0x52, 0xb7, 0x74, 0x13, 0x29, 0x3a, 0x3, 0xd4, 0xd0}

, "kCBMsgArgATTMTU":104}}
2017/05/11 22:28:47 [DEBUG] Peripheral Connected
2017/05/11 22:28:47 [DEBUG] Newtmgr Service Found
2017/05/11 22:28:47 [DEBUG] Newtmgr Characteristic Found
2017/05/11 22:28:47 [DEBUG] Writing newtmgr request &

{Op:0 Flags:0 Len:0 Group:0 Seq:0 Id:3 Data:[]}

2017/05/11 22:28:47 [DEBUG] Serializing request &

{Op:0 Flags:0 Len:0 Group:0 Seq:0 Id:3 Data:[]}

into buffer [0 0 0 0 0 0 0 3]
2017/05/11 22:28:47 [DEBUG] Tx packet dump:
00000000 00 00 00 00 00 00 00 03 |........|

2017/05/11 22:28:47 [DEBUG] Write BLE Packet:buf:: len::8
2017/05/11 22:28:47 [DEBUG] Read BLE Packet:buf::l?brcfmpools?fmsys_1?fblksiz$enblks
enfree cmin?wble_hci_ram_evt_hi_pool?fblksizHenblkse len::101
2017/05/11 22:28:47 [DEBUG] Rx packet dump:
00000000 01 00 02 6c 00 00 00 03 bf 62 72 63 00 66 6d 70 |...l.....brc.fmp|
00000010 6f 6f 6c 73 bf 66 6d 73 79 73 5f 31 bf 66 62 6c |ools.fmsys_1.fbl|
00000020 6b 73 69 7a 19 01 24 65 6e 62 6c 6b 73 0c 65 6e |ksiz..$enblks.en|
00000030 66 72 65 65 09 63 6d 69 6e 00 ff 77 62 6c 65 5f |free.cmin..wble_|
00000040 68 63 69 5f 72 61 6d 5f 65 76 74 5f 68 69 5f 70 |hci_ram_evt_hi_p|
00000050 6f 6f 6c bf 66 62 6c 6b 73 69 7a 18 48 65 6e 62 |ool.fblksiz.Henb|
00000060 6c 6b 73 02 65 |lks.e|

2017/05/11 22:28:47 [DEBUG] Deserialized response &

{Op:1 Flags:0 Len:620 Group:0 Seq:0 Id:3 Data:[191 98 114 99 0 102 109 112 111 111 108 115 191 102 109 115 121 115 95 49 191 102 98 108 107 115 105 122 25 1 36 101 110 98 108 107 115 12 101 110 102 114 101 101 9 99 109 105 110 0 255 119 98 108 101 95 104 99 105 95 114 97 109 95 101 118 116 95 104 105 95 112 111 111 108 191 102 98 108 107 115 105 122 24 72 101 110 98 108 107 115 2 101]}

2017/05/11 22:28:47 [DEBUG] Read BLE Packet:buf::nfreecmin?wble_hci_ram_evt_lo_pool?fblksizHenblkenfrecmi?rble_hs_hci_ev_pool?fblksizenblks
len::101
2017/05/11 22:28:47 [DEBUG] Rx packet dump:
00000000 6e 66 72 65 65 02 63 6d 69 6e 00 ff 77 62 6c 65 |nfree.cmin..wble|
00000010 5f 68 63 69 5f 72 61 6d 5f 65 76 74 5f 6c 6f 5f |hci_ram_evt_lo|
00000020 70 6f 6f 6c bf 66 62 6c 6b 73 69 7a 18 48 65 6e |pool.fblksiz.Hen|
00000030 62 6c 6b 73 08 65 6e 66 72 65 65 08 63 6d 69 6e |blks.enfree.cmin|
00000040 08 ff 72 62 6c 65 5f 68 73 5f 68 63 69 5f 65 76 |..rble_hs_hci_ev|
00000050 5f 70 6f 6f 6c bf 66 62 6c 6b 73 69 7a 10 65 6e |_pool.fblksiz.en|
00000060 62 6c 6b 73 0a |blks.|

2017/05/11 22:28:47 [DEBUG] Read BLE Packet:buf::enfree
cmin ?pble_hs_conn_pool?fblksizTenblksenfreecmin?sble_l2cap_chan_pool?fblksizenblksenfr len::101
2017/05/11 22:28:47 [DEBUG] Rx packet dump:
00000000 65 6e 66 72 65 65 0a 63 6d 69 6e 09 ff 70 62 6c |enfree.cmin..pbl|
00000010 65 5f 68 73 5f 63 6f 6e 6e 5f 70 6f 6f 6c bf 66 |e_hs_conn_pool.f|
00000020 62 6c 6b 73 69 7a 18 54 65 6e 62 6c 6b 73 01 65 |blksiz.Tenblks.e|
00000030 6e 66 72 65 65 00 63 6d 69 6e 00 ff 73 62 6c 65 |nfree.cmin..sble|
00000040 5f 6c 32 63 61 70 5f 63 68 61 6e 5f 70 6f 6f 6c |_l2cap_chan_pool|
00000050 bf 66 62 6c 6b 73 69 7a 18 1c 65 6e 62 6c 6b 73 |.fblksiz..enblks|
00000060 03 65 6e 66 72 |.enfr|

2017/05/11 22:28:47 [DEBUG] Read BLE Packet:buf::eecmin?wble_l2cap_sig_proc_pool?fblksizenblksenfreecmin?xle_att_svr_prep_entry_pool?fblksiz
e len::101
2017/05/11 22:28:47 [DEBUG] Rx packet dump:
00000000 65 65 00 63 6d 69 6e 00 ff 77 62 6c 65 5f 6c 32 |ee.cmin..wble_l2|
00000010 63 61 70 5f 73 69 67 5f 70 72 6f 63 5f 70 6f 6f |cap_sig_proc_poo|
00000020 6c bf 66 62 6c 6b 73 69 7a 14 65 6e 62 6c 6b 73 |l.fblksiz.enblks|
00000030 01 65 6e 66 72 65 65 01 63 6d 69 6e 01 ff 78 1b |.enfree.cmin..x.|
00000040 62 6c 65 5f 61 74 74 5f 73 76 72 5f 70 72 65 70 |ble_att_svr_prep|
00000050 5f 65 6e 74 72 79 5f 70 6f 6f 6c bf 66 62 6c 6b |_entry_pool.fblk|
00000060 73 69 7a 0c 65 |siz.e|

2017/05/11 22:28:47 [DEBUG] Read BLE Packet:buf::ksenfreecmin?vble_att_svr_entry_pool?fblksizenblks%enfreecmin?vble_gatts_clt_cfg_pool?fblksiz len::101
2017/05/11 22:28:47 [DEBUG] Rx packet dump:
00000000 6b 73 04 65 6e 66 72 65 65 04 63 6d 69 6e 04 ff |ks.enfree.cmin..|
00000010 76 62 6c 65 5f 61 74 74 5f 73 76 72 5f 65 6e 74 |vble_att_svr_ent|
00000020 72 79 5f 70 6f 6f 6c bf 66 62 6c 6b 73 69 7a 14 |ry_pool.fblksiz.|
00000030 65 6e 62 6c 6b 73 18 25 65 6e 66 72 65 65 00 63 |enblks.%enfree.c|
00000040 6d 69 6e 00 ff 76 62 6c 65 5f 67 61 74 74 73 5f |min..vble_gatts_|
00000050 63 6c 74 5f 63 66 67 5f 70 6f 6f 6c bf 66 62 6c |clt_cfg_pool.fbl|
00000060 6b 73 69 7a 10