Thanks Chris!
Tried some more with the new upstreamed code but a few more issues...
Still had to add the serial transport to bleprph, not sure if you left that
out of there on purpose for code size..
- mgmt/newtmgr/transport/nmgr_shell
newt run split-nrf51dk 0
and it responds to newtmgr serial commands now..
But never blinks..
Looks like its hitting os_start in the loader because
rc = split_app_go(&entry, true); returns -1
because
(gdb) p split_mode_cur
$6 = 0 '\000'
which is SPLIT_MODE_LOADER
I think it should be SPLIT_MODE_APP?? maybe?
Also I just decided to go through with newtmgr upload commands, but they
crash:
Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$ newtmgr image list -c
serial1
Images:
slot=0
version: 0.0.0
bootable: true
flags: active confirmed
hash: ff846c585a34185c24f46166547a6447f1c82de94fe2ab93033dc40903d873b1
slot=1
version: 0.0.0
bootable: false
flags:
hash: 75379446f1c26f11b86f521f06636c0fcd4c28f3b14e192fe3331ba4504330ff
Split status: matching
Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$ newtmgr image test
75379446f1c26f11b86f521f06636c0fcd4c28f3b14e192fe3331ba4504330ff -c serial1
Images:
slot=0
version: 0.0.0
bootable: true
flags: active confirmed
hash: ff846c585a34185c24f46166547a6447f1c82de94fe2ab93033dc40903d873b1
slot=1
version: 0.0.0
bootable: false
flags: pending
hash: 75379446f1c26f11b86f521f06636c0fcd4c28f3b14e192fe3331ba4504330ff
Split status: matching
Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$ newtmgr reset
-cserial1
Done
Crashes....
(gdb) p *g_current_task
$1 = {t_stackptr = 0x20004000, t_stacktop = 0xc1, t_stacksize = 313,
t_taskid = 0 '\000', t_prio = 0 '\000', t_state = 57 '9', t_flags = 1
'\001',
t_lockcnt = 0 '\000', t_pad = 0 '\000', t_name = 0x0, t_func = 0x0, t_arg
= 0x0, t_obj = 0x0, t_sanity_check = {sc_checkin_last = 0,
sc_checkin_itvl = 0, sc_func = 0x0, sc_arg = 0x139, sc_next = {sle_next
= 0x0}}, t_next_wakeup = 0, t_run_time = 313, t_ctx_sw_cnt = 313,
t_os_task_list = {stqe_next = 0x139}, t_os_list = {tqe_next = 0x139,
tqe_prev = 0x139}, t_obj_list = {sle_next = 0x139}}
(gdb) bt
#0 0xfffffffe in ?? ()
#1 <signal handler called>
#2 0x00000000 in ?? ()
#3 0x00000000 in ?? ()
(gdb)
Presumably the gdb session cant persist through reset... so just kill that
and start over
Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$ newtmgr image confirm
-cserial1
Images:
slot=0
version: 0.0.0
bootable: true
flags: active confirmed
hash: ff846c585a34185c24f46166547a6447f1c82de94fe2ab93033dc40903d873b1
slot=1
version: 0.0.0
bootable: false
flags:
hash: 75379446f1c26f11b86f521f06636c0fcd4c28f3b14e192fe3331ba4504330ff
Split status: matching
Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$ newtmgr image upload
/Users/jacobrosenthal/Downloads/mynewt-hr-observer/bin/targets/split-nrf51dk/loader/apps/bleprph/bleprph.elf
-cserial1 -t -ldebug
2017/01/17 17:45:16 [DEBUG] Writing newtmgr request &{Op:2 Flags:0 Len:7
Group:0 Seq:0 Id:1 Data:[161 100 101 99 104 111 0]}
2017/01/17 17:45:16 [DEBUG] Serializing request &{Op:2 Flags:0 Len:7
Group:0 Seq:0 Id:1 Data:[161 100 101 99 104 111 0]} into buffer [2 0 0 7 0
0 0 1 161 100 101 99 104 111 0]
2017/01/17 17:45:16 [DEBUG] Tx packet dump:
00000000 02 00 00 07 00 00 00 01 a1 64 65 63 68 6f 00
|.........decho.|
2017/01/17 17:45:16 [INFO] Outgoing:
00000000 06 09 |..|
2017/01/17 17:45:16 [DEBUG] Writing [6 9] to data channel
2017/01/17 17:45:16 [INFO] Outgoing:
00000000 41 42 45 43 41 41 41 48 41 41 41 41 41 61 46 6b
|ABECAAAHAAAAAaFk|
00000010 5a 57 4e 6f 62 77 44 33 7a 51 3d 3d |ZWNobwD3zQ==|
2017/01/17 17:45:16 [DEBUG] Writing [65 66 69 67 65 65 65 72 65 65 65 65 65
97 70 107 90 87 78 111 98 119 68 51 122 81 61 61] to data channel
2017/01/17 17:45:16 [INFO] Outgoing:
00000000 0a |.|
2017/01/17 17:45:16 [DEBUG] Writing [10] to data channel
2017/01/17 17:45:16 [INFO] Incoming:
00000000 06 09 41 42 45 43 41 41 41 48 41 41 41 41 41 61
|..ABECAAAHAAAAAa|
00000010 46 6b 5a 57 4e 6f 62 77 44 33 7a 51 3d 3d |FkZWNobwD3zQ==|
2017/01/17 17:45:16 [DEBUG] Reading [6 9 65 66 69 67 65 65 65 72 65 65 65
65 65 97 70 107 90 87 78 111 98 119 68 51 122 81 61 61] from data channel
2017/01/17 17:45:16 [DEBUG] Rx packet dump:
00000000 02 00 00 07 00 00 00 01 a1 64 65 63 68 6f 00
|.........decho.|
2017/01/17 17:45:16 [DEBUG] Deserialized response &{Op:2 Flags:0 Len:7
Group:0 Seq:0 Id:1 Data:[161 100 101 99 104 111 0]}
2017/01/17 17:45:16 [INFO] Incoming:
00000000 0d |.|
2017/01/17 17:45:16 [DEBUG] Reading [13] from data channel
2017/01/17 17:45:16 [INFO] Incoming:
00000000 06 09 41 41 6f 44 41 41 41 41 41 41 41 41 41 64
|..AAoDAAAAAAAAAd|
00000010 68 55 |hU|
2017/01/17 17:45:16 [DEBUG] Reading [6 9 65 65 111 68 65 65 65 65 65 65 65
65 65 100 104 85] from data channel
2017/01/17 17:45:16 [DEBUG] Rx packet dump:
00000000 03 00 00 00 00 00 00 01 |........|
2017/01/17 17:45:16 [DEBUG] Deserialized response &{Op:3 Flags:0 Len:0
Group:0 Seq:0 Id:1 Data:[]}
2017/01/17 17:45:16 [DEBUG] Writing newtmgr request &{Op:2 Flags:0 Len:78
Group:1 Seq:0 Id:1 Data:[163 100 100 97 116 97 88 56 127 69 76 70 1 1 1 0 0
0 0 0 0 0 0 0 2 0 40 0 1 0 0 0 189 130 0 0 52 0 0 0 196 239 20 0 2 2 0 5 52
0 32 0 5 0 40 0 23 0 20 0 1 0 0 112 99 108 101 110 26 0 22 132 215 99 111
102 102 0]}
2017/01/17 17:45:16 [DEBUG] Serializing request &{Op:2 Flags:0 Len:78
Group:1 Seq:0 Id:1 Data:[163 100 100 97 116 97 88 56 127 69 76 70 1 1 1 0 0
0 0 0 0 0 0 0 2 0 40 0 1 0 0 0 189 130 0 0 52 0 0 0 196 239 20 0 2 2 0 5 52
0 32 0 5 0 40 0 23 0 20 0 1 0 0 112 99 108 101 110 26 0 22 132 215 99 111
102 102 0]} into buffer [2 0 0 78 0 1 0 1 163 100 100 97 116 97 88 56 127
69 76 70 1 1 1 0 0 0 0 0 0 0 0 0 2 0 40 0 1 0 0 0 189 130 0 0 52 0 0 0 196
239 20 0 2 2 0 5 52 0 32 0 5 0 40 0 23 0 20 0 1 0 0 112 99 108 101 110 26 0
22 132 215 99 111 102 102 0]
2017/01/17 17:45:16 [DEBUG] Tx packet dump:
00000000 02 00 00 4e 00 01 00 01 a3 64 64 61 74 61 58 38
|...N.....ddataX8|
00000010 7f 45 4c 46 01 01 01 00 00 00 00 00 00 00 00 00
|.ELF............|
00000020 02 00 28 00 01 00 00 00 bd 82 00 00 34 00 00 00
|..(.........4...|
00000030 c4 ef 14 00 02 02 00 05 34 00 20 00 05 00 28 00 |........4.
...(.|
00000040 17 00 14 00 01 00 00 70 63 6c 65 6e 1a 00 16 84
|.......pclen....|
00000050 d7 63 6f 66 66 00 |.coff.|
2017/01/17 17:45:16 [INFO] Outgoing:
00000000 06 09 |..|
2017/01/17 17:45:16 [DEBUG] Writing [6 9] to data channel
2017/01/17 17:45:16 [INFO] Outgoing:
00000000 41 46 67 43 41 41 42 4f 41 41 45 41 41 61 4e 6b
|AFgCAABOAAEAAaNk|
00000010 5a 47 46 30 59 56 67 34 66 30 56 4d 52 67 45 42
|ZGF0YVg4f0VMRgEB|
00000020 41 51 41 41 41 41 41 41 41 41 41 41 41 41 49 41
|AQAAAAAAAAAAAAIA|
00000030 4b 41 41 42 41 41 41 41 76 59 49 41 41 44 51 41
|KAABAAAAvYIAADQA|
00000040 41 41 44 45 37 78 51 41 41 67 49 41 42 54 51 41
|AADE7xQAAgIABTQA|
00000050 49 41 41 46 41 43 67 41 46 77 41 55 41 41 45 41
|IAAFACgAFwAUAAEA|
00000060 41 48 42 6a 62 47 56 75 47 67 41 57 68 4e 64 6a
|AHBjbGVuGgAWhNdj|
00000070 62 32 5a 6d 41 4c 52 39 |b2ZmALR9|
2017/01/17 17:45:16 [DEBUG] Writing [65 70 103 67 65 65 66 79 65 65 69 65
65 97 78 107 90 71 70 48 89 86 103 52 102 48 86 77 82 103 69 66 65 81 65 65
65 65 65 65 65 65 65 65 65 65 73 65 75 65 65 66 65 65 65 65 118 89 73 65 65
68 81 65 65 65 68 69 55 120 81 65 65 103 73 65 66 84 81 65 73 65 65 70 65
67 103 65 70 119 65 85 65 65 69 65 65 72 66 106 98 71 86 117 71 103 65 87
104 78 100 106 98 50 90 109 65 76 82 57] to data channel
2017/01/17 17:45:16 [INFO] Outgoing:
00000000 0a |.|
2017/01/17 17:45:16 [DEBUG] Writing [10] to data channel
2017/01/17 17:45:16 [INFO] Incoming:
2017/01/17 17:45:16 [DEBUG] Reading [] from data channel
2017/01/17 17:45:16 [INFO] Incoming:
00000000 06 09 41 42 41 44 41 41 41 47 41 41 45 41 41 62
|..ABADAAAGAAEAAb|
00000010 39 69 63 6d 4d 44 2f 32 70 67 |9icmMD/2pg|
2017/01/17 17:45:16 [DEBUG] Reading [6 9 65 66 65 68 65 65 65 71 65 65 69
65 65 98 57 105 99 109 77 68 47 50 112 103] from data channel
2017/01/17 17:45:16 [DEBUG] Rx packet dump:
00000000 03 00 00 06 00 01 00 01 bf 62 72 63 03 ff |.........brc..|
2017/01/17 17:45:16 [DEBUG] Deserialized response &{Op:3 Flags:0 Len:6
Group:1 Seq:0 Id:1 Data:[191 98 114 99 3 255]}
2017/01/17 17:45:16 [DEBUG] Writing newtmgr request &{Op:2 Flags:0 Len:7
Group:0 Seq:0 Id:1 Data:[161 100 101 99 104 111 1]}
2017/01/17 17:45:16 [DEBUG] Serializing request &{Op:2 Flags:0 Len:7
Group:0 Seq:0 Id:1 Data:[161 100 101 99 104 111 1]} into buffer [2 0 0 7 0
0 0 1 161 100 101 99 104 111 1]
2017/01/17 17:45:16 [DEBUG] Tx packet dump:
00000000 02 00 00 07 00 00 00 01 a1 64 65 63 68 6f 01
|.........decho.|
2017/01/17 17:45:16 [INFO] Outgoing:
00000000 06 09 |..|
2017/01/17 17:45:16 [DEBUG] Writing [6 9] to data channel
2017/01/17 17:45:16 [INFO] Outgoing:
00000000 41 42 45 43 41 41 41 48 41 41 41 41 41 61 46 6b
|ABECAAAHAAAAAaFk|
00000010 5a 57 4e 6f 62 77 48 6e 37 41 3d 3d |ZWNobwHn7A==|
2017/01/17 17:45:16 [DEBUG] Writing [65 66 69 67 65 65 65 72 65 65 65 65 65
97 70 107 90 87 78 111 98 119 72 110 55 65 61 61] to data channel
2017/01/17 17:45:16 [INFO] Outgoing:
00000000 0a |.|
2017/01/17 17:45:16 [DEBUG] Writing [10] to data channel
2017/01/17 17:45:16 [INFO] Incoming:
2017/01/17 17:45:16 [DEBUG] Reading [] from data channel
2017/01/17 17:45:16 [INFO] Incoming:
00000000 06 09 41 41 6f 44 41 41 41 41 41 41 41 41 41 64
|..AAoDAAAAAAAAAd|
00000010 68 55 |hU|
2017/01/17 17:45:16 [DEBUG] Reading [6 9 65 65 111 68 65 65 65 65 65 65 65
65 65 100 104 85] from data channel
2017/01/17 17:45:16 [DEBUG] Rx packet dump:
00000000 03 00 00 00 00 00 00 01 |........|
2017/01/17 17:45:16 [DEBUG] Deserialized response &{Op:3 Flags:0 Len:0
Group:0 Seq:0 Id:1 Data:[]}
2017/01/17 17:45:16 [DEBUG] goroutine 1 [running]:
mynewt.apache.org/newt/newtmgr/vendor/mynewt.apache.org/newt/util.NewNewtError(0xc420167e10,
0xf, 0xc4202f1b28)
/Users/jacobrosenthal/dev/go/src/
mynewt.apache.org/newt/newtmgr/vendor/mynewt.apache.org/newt/util/util.go:75
+0x111
mynewt.apache.org/newt/newtmgr/protocol.DecodeImageUploadResponse(0xc420167dc0,
0x6, 0x8, 0x0, 0x1, 0x0)
/Users/jacobrosenthal/dev/go/src/
mynewt.apache.org/newt/newtmgr/protocol/imageupload.go:98 +0x1c6
mynewt.apache.org/newt/newtmgr/cli.imageUploadCmd(0xc42016f680,
0xc420014400, 0x1, 0x4)
/Users/jacobrosenthal/dev/go/src/
mynewt.apache.org/newt/newtmgr/cli/image.go:362 +0x4e0
mynewt.apache.org/newt/newtmgr/vendor/github.com/spf13/cobra.(*Command).execute(0xc42016f680,
0xc4200143c0, 0x4, 0x4, 0xc42016f680, 0xc4200143c0)
/Users/jacobrosenthal/dev/go/src/
mynewt.apache.org/newt/newtmgr/vendor/github.com/spf13/cobra/command.go:636
+0x443
mynewt.apache.org/newt/newtmgr/vendor/github.com/spf13/cobra.(*Command).ExecuteC(0xc42016e000,
0xc42016eb40, 0xc42016e240, 0xc420166f90)
/Users/jacobrosenthal/dev/go/src/
mynewt.apache.org/newt/newtmgr/vendor/github.com/spf13/cobra/command.go:722
+0x367
mynewt.apache.org/newt/newtmgr/vendor/github.com/spf13/cobra.(*Command).Execute(0xc42016e000,
0x40d65bc, 0xc4200001a0)
/Users/jacobrosenthal/dev/go/src/
mynewt.apache.org/newt/newtmgr/vendor/github.com/spf13/cobra/command.go:681
+0x2b
main.main()
/Users/jacobrosenthal/dev/go/src/
mynewt.apache.org/newt/newtmgr/newtmgr.go:25 +0x2f
goroutine 17 [syscall, locked to thread]:
runtime.goexit()
/usr/local/Cellar/go/1.7.4_1/libexec/src/runtime/asm_amd64.s:2086 +0x1
goroutine 20 [syscall]:
os/signal.signal_recv(0x0)
/usr/local/Cellar/go/1.7.4_1/libexec/src/runtime/sigqueue.go:116 +0x157
os/signal.loop()
/usr/local/Cellar/go/1.7.4_1/libexec/src/os/signal/signal_unix.go:22 +0x22
created by os/signal.init.1
/usr/local/Cellar/go/1.7.4_1/libexec/src/os/signal/signal_unix.go:28 +0x41
Error: Target error: 3
Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$
On Mon, Jan 16, 2017 at 3:35 PM, Christopher Collins <[email protected]>
wrote:
> Just a follow up for the list-
>
> It turns out there were a number of issues with split images. I believe
> they have all been resolved now. Some of the required changes were
> non-trivial, so I wanted to summarize what I did.
>
> 1. bleprph doesn't jump to app (slot 2).
>
> This one is straightforward. The bleprph app wasn't written to behave
> as a loader. Rather, it always started the OS, even when configured to
> run the second stage app. The fix was just to copy and paste the
> generic loader code from slinky.
>
> 2. Jump from loader to app required too much RAM.
>
> When a loader transitions to the second stage app, it executes a
> modified version of the boot loader. The boot loader was using quite a
> bit of RAM for caching information about the layout of sectors within
> the image slots. In normal, non-split, operation, such RAM usage isn't
> a problem because there is no OS running, and therefore no other code to
> share memory with. In the modified version that runs during the split
> transition, other code *is* running, so RAM for the sector cache gets
> allocated via malloc(). About 4kB was getting malloced here, which was
> failing for me when running on the 16 kB RAM nRF51dk BSP. The fix is to
> not cache the sector data, but to read it when needed.
>
> 3. Loader-only packages were not getting initialized in the second stage
> app.
>
> This was a bug in the newt tool. When generating the sysinit_app()
> function, the tool excluded packages which are not explicitly referenced
> in the app's dependency tree. This is wrong; all packages should get
> initialized in the second stage app.
>
> Thanks,
> Chris
>
>
> On Fri, Jan 13, 2017 at 04:38:25PM -0700, Jacob Rosenthal wrote:
> > Ah, I expected gdb of optimized split code to be a nightmare and hadnt
> > tried yet.
> > newtmgr has never crashed.. it just hangs forever
> >
> > I cant get the SOFT anymore now..... hrmmm Just hanging out here..
> > (gdb) where
> > #0 os_tick_idle (ticks=1189) at
> > repos/apache-mynewt-core/hw/mcu/nordic/nrf51xxx/src/hal_os_tick.c:158
> > #1 0x00008c1e in os_idle_task (arg=<optimized out>) at
> > repos/apache-mynewt-core/kernel/os/src/os.c:110
> > #2 0x00000000 in ?? ()
> > (gdb) c
> >
> > Any chance I could impose on you to debug in irc with me sometime?
> >
> >
> > On Thu, Jan 12, 2017 at 9:42 PM, Christopher Collins <
> [email protected]>
> > wrote:
> >
> > > Hi Jacob,
> > >
> > > If that reboot log entry is recent, it looks like your device is
> > > crashing. A reason of "SOFT" indicates a firmware crash [*]. I would
> > > say the quickest way to debug this is to run the code in gdb. You can
> > > do this with the "newt run" command:
> > >
> > > newt run <target-name> 0
> > >
> > > When gdb comes up, type c and press enter. Then in a different shell,
> > > send a newtmgr command to the device. If device crashes, gdb should
> > > indicate such. If Mynewt crashes, can you please type the following
> > > commands in gdb:
> > >
> > > bt
> > > p *g_current_task
> > > p os_msys_init_1_mempool
> > >
> > > And send the output?
> > >
> > > Thanks,
> > > Chris
> > >
> > > [*] Augmenting the reboot log entry with the line number and filename
> > > where the crash occurred is on the to do list.
> > >
> > >
> > > On Thu, Jan 12, 2017 at 08:41:03PM -0700, Jacob Rosenthal wrote:
> > >
> > >
> > >
> > > > turned off a ton more bluetooth shit for more ram
> > > >
> > > > both still hang:
> > > > newtmgr -c serial1 logs log_list
> > > > newtmgr -c serial1 image list
> > > >
> > > > but log in shell now has:
> > > > newtmgr 4976:Dumping log reboot_log
> > > >
> > > >
> > > > On Thu, Jan 12, 2017 at 8:33 PM, Jacob Rosenthal <
> > > [email protected]>
> > > > wrote:
> > > >
> > > > > log on shell shows lots of these
> > > > >
> > > > > 9050:[0] rsn:SOFT, cnt:1, img:0.0.0.0
> > > > >
> > > > > On Thu, Jan 12, 2017 at 8:28 PM, Jacob Rosenthal <
> > > [email protected]>
> > > > > wrote:
> > > > >
> > > > >> All newtmgr commands on serial are hanging indefinitely.
> > > > >> Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$ newtmgr -c
> > > serial1
> > > > >> image list
> > > > >> ^C
> > > > >> Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$ newtmgr
> conn
> > > show
> > > > >> Connection profiles:
> > > > >> serial1: type=serial, connstring='/dev/tty.usbmodem1411'
> > > > >> Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$
> > > > >>
> > > > >> Looks like it works for the splitty/slinky demo
> > > > >> Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$ newtmgr -c
> > > serial1
> > > > >> image list
> > > > >> Images:
> > > > >> slot=0
> > > > >> version: 0.0.0
> > > > >> bootable: true
> > > > >> flags: active confirmed
> > > > >> hash: 21439de02cbf31626856374f44cbd4
> > > 90fd6def3ce3062b63d55ed2c19a8b
> > > > >> 2b83
> > > > >> slot=1
> > > > >> version: 0.0.0
> > > > >> bootable: false
> > > > >> flags:
> > > > >> hash: 8b64ea89bf0495c0ccb25b96b3a7f0
> > > 6fd5e540e221f9659f9bc6b0d0d303
> > > > >> d6f1
> > > > >> Split status: matching
> > > > >> Jacobs-MacBook-Air:mynewt-hr-observer jacobrosenthal$
> > > > >>
> > > > >> Ram issue? Whats a good way to see a log of the failed attempt
> since I
> > > > >> have the shell?
> > > > >>
> > > > >>
> > > > >>
> > > > >> On Thu, Jan 12, 2017 at 7:51 PM, Christopher Collins <
> > > [email protected]
> > > > >> > wrote:
> > > > >>
> > > > >>> On Thu, Jan 12, 2017 at 07:06:37PM -0700, Jacob Rosenthal wrote:
> > > > >>> > Still ok... and Im able to interact with shell over serial
> and I
> > > > >>> think its
> > > > >>> > advertising!? Not sure why my newtmgr wont connect then..
> Ideas to
> > > > >>> > troubleshoot?
> > > > >>>
> > > > >>> So you are sending newtmgr commands over serial? Do all commands
> > > fail,
> > > > >>> or just image list?
> > > > >>>
> > > > >>> > Also I was digging and found someone already PRed a ble
> transport
> > > for
> > > > >>> > newtmgr https://github.com/apache/
> incubator-mynewt-core/pull/73/
> > > files
> > > > >>> > but the api is a bit different now.. Anyone using that?
> > > > >>>
> > > > >>> Yes, the newtmgr BLE characteristic is being used and should
> work.
> > > The
> > > > >>> newtmgr command line tool has rudimentary support for BLE, but
> only
> > > when
> > > > >>> run on linux.
> > > > >>>
> > > > >>> Thanks,
> > > > >>> Chris
> > > > >>>
> > > > >>
> > > > >>
> > > > >
> > >
>
