newtmgr hanging in image upload

[jfclere]

I am trying to send an image to an Adafruit Feather nRF52 Pro but the upload hangs in the first bloc:

root@fedora:/home/jfclere/dev/try# /home/jfclere/go/bin/newtmgr -c mybleprph image upload bin/targets/DK_blinky/app/apps/blinky/blinky.img -l DEBUG
DEBU[2024-09-08 21:52:23.956] Using connection profile: name=mybleprph type=ble connstring=peer_name=Bluefruit52 
DEBU[2024-09-08 21:52:24.265] Connecting to peer                           
DEBU[2024-09-08 21:52:24.424] Exchanging MTU                               
DEBU[2024-09-08 21:52:24.436] Exchanged MTU; ATT MTU = 527                 
DEBU[2024-09-08 21:52:24.436] Discovering profile                          
DEBU[2024-09-08 21:52:24.692] Subscribing to NMP response characteristic   
 0 / 11584 [--------------------------------------------------------------------------------------------------------------------------------------------------------------]   0.00%DEBU[2024-09-08 21:52:24.707] Encoded &{NmpBase:{hdr:{Op:2 Flags:0 Len:0 Group:1 Seq:131 Id:1}} ImageNum:0 Off:0 Len:11584 DataSha:[249 84 13 16 227 133 36 139 162 228 255 174 0 27 54 230 88 236 4 52 230 243 236 238 64 178 6 225 252 208 14 14] Upgrade:false Data:[61 184 243 150 0 0 0 0 32 0 0 0 248 44 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 0 0 1 32 33 130 0 0 79 131 0 0 81 131 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 159 130 0 0 0 0 0 0 0 0 0 0 229 130 0 0 15 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 0 0 0 0 0 0 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 77 131 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]}

Other commands seem to work: (taskstat, image list)

oot@fedora:/home/jfclere/dev/try# /home/jfclere/go/bin/newtmgr -c mybleprph image list -l DEBUG
DEBU[2024-09-08 22:02:56.312] Using connection profile: name=mybleprph type=ble connstring=peer_name=Bluefruit52 
DEBU[2024-09-08 22:02:56.62] Connecting to peer                           
DEBU[2024-09-08 22:02:56.755] Exchanging MTU                               
DEBU[2024-09-08 22:02:56.767] Exchanged MTU; ATT MTU = 527                 
DEBU[2024-09-08 22:02:56.767] Discovering profile                          
DEBU[2024-09-08 22:02:57.031] Subscribing to NMP response characteristic   
DEBU[2024-09-08 22:02:57.046] {add-nmp-listener} [bll_sesn.go:392] seq=17  
DEBU[2024-09-08 22:02:57.046] Encoded &{NmpBase:{hdr:{Op:0 Flags:0 Len:0 Group:1 Seq:17 Id:0}}} to:
00000000  a0                                                |.| 
DEBU[2024-09-08 22:02:57.046] Encoded:
00000000  00 00 00 01 00 01 11 00  a0                       |.........| 
DEBU[2024-09-08 22:02:57.046] Tx NMP request: 00000000  00 00 00 01 00 01 11 00  a0                       |.........| 
DEBU[2024-09-08 22:02:57.063] rx nmp response: 00000000  01 00 00 86 00 01 11 00  bf 66 69 6d 61 67 65 73  |.........fimages|
00000010  9f bf 64 73 6c 6f 74 00  67 76 65 72 73 69 6f 6e  |..dslot.gversion|
00000020  65 30 2e 31 2e 30 64 68  61 73 68 58 20 be 52 a2  |e0.1.0dhashX .R.|
00000030  55 c2 55 46 da cc 49 7d  62 fa ea 91 04 59 90 3a  |U.UF..I}b....Y.:|
00000040  1c 19 16 ce 83 16 97 d4  0f c2 c2 06 89 68 62 6f  |.............hbo|
00000050  6f 74 61 62 6c 65 f5 67  70 65 6e 64 69 6e 67 f4  |otable.gpending.|
00000060  69 63 6f 6e 66 69 72 6d  65 64 f5 66 61 63 74 69  |iconfirmed.facti|
00000070  76 65 f5 69 70 65 72 6d  61 6e 65 6e 74 f4 ff ff  |ve.ipermanent...|
00000080  6b 73 70 6c 69 74 53 74  61 74 75 73 00 ff        |ksplitStatus..| 
DEBU[2024-09-08 22:02:57.063] Received nmp rsp: &{NmpBase:{hdr:{Op:1 Flags:0 Len:134 Group:1 Seq:17 Id:0}} Rc:0 Images:[{NmpBase:{hdr:{Op:0 Flags:0 Len:0 Group:0 Seq:0 Id:0}} Image:0 Slot:0 Version:0.1.0 Hash:[190 82 162 85 194 85 70 218 204 73 125 98 250 234 145 4 89 144 58 28 25 22 206 131 22 151 212 15 194 194 6 137] Bootable:true Pending:false Confirmed:true Active:true Permanent:false}] SplitStatus:N/A} 
DEBU[2024-09-08 22:02:57.063] {remove-nmp-listener} [bll_sesn.go:392] seq=17 
Images:
 image=0 slot=0
    version: 0.1.0
    bootable: true
    flags: active confirmed
    hash: be52a255c25546dacc497d62faea910459903a1c1916ce831697d40fc2c20689
Split status: N/A (0)

[jfclere]

trace.txt
the btmon output, to read btmon -r trace.txt

[sjanc]

Hi,

This is due to main stack issue, bleprph sample reduce this to 512, but it may be to low for certain device
I was able to reproduce this locally on nrf52832 when testing for 1.13 release, setting OS_MAIN_STACK_SIZE:768 in your target should fix it

I'll update default accordingly, and post release we will work on reducing stack usage a bit for this