#178 stlink-v2-1 fails to initialize with openocd (sometimes) when trace output was previously enabled

[Cody Schafer]

When starting openocd up again after I've previously had trace output enabled (in both target & stlink) sometimes causes openocd to consistently fail to initialize. After starting openocd with the target reset button held down, it initiallizes succesfully.


[cody@franklin ~]$ cd wrist3/
(failed reverse-i-search)`opeoc': cd d/^Cenocd-code/
[cody@franklin wrist3]$ sudo ~/.local/bin/openocd -c gdb_port\ 3333 -f board/st_nucleo_f4.cfg
Open On-Chip Debugger 0.10.0+dev-00281-g64f1f7b1-dirty (2018-01-25-14:00)
Licensed under GNU GPL v2
For bug reports, read
http://openocd.org/doc/doxygen/bugs.html
Info : The selected transport took over low-level target control. The results might differ compared to plain JTAG/SWD
adapter speed: 2000 kHz
adapter_nsrst_delay: 100
none separate
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : clock speed 1800 kHz
Info : STLINK v2 JTAG v29 API v2 SWIM v18 VID 0x0483 PID 0x374B
Info : using stlink api v2
Info : Target voltage: 74.727272
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 100ms
Info : Previous state query failed, trying to reconnect
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 300ms
Info : Listening on port 3333 for gdb connections
Info : Previous state query failed, trying to reconnect
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 700ms
Info : Previous state query failed, trying to reconnect
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 1500ms
^C
[cody@franklin wrist3]$ sudo ~/.local/bin/openocd -c gdb_port\ 3333 -f board/st_nucleo_f4.cfg
Open On-Chip Debugger 0.10.0+dev-00281-g64f1f7b1-dirty (2018-01-25-14:00)
Licensed under GNU GPL v2
For bug reports, read
http://openocd.org/doc/doxygen/bugs.html
Info : The selected transport took over low-level target control. The results might differ compared to plain JTAG/SWD
adapter speed: 2000 kHz
adapter_nsrst_delay: 100
none separate
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : clock speed 1800 kHz
Info : STLINK v2 JTAG v29 API v2 SWIM v18 VID 0x0483 PID 0x374B
Info : using stlink api v2
Info : Target voltage: 3.245850
Info : stm32f4x.cpu: hardware has 0 breakpoints, 0 watchpoints
Error: mem2array: Read @ 0xe0042004, w=4, cnt=1, failed
/home/cody/.local/bin/../share/openocd/scripts/mem_helper.tcl:6: Error:
in procedure 'init'
in procedure 'ocd_bouncer'
in procedure 'mmw'
in procedure 'mrw' called at file "/home/cody/.local/bin/../share/openocd/scripts/mem_helper.tcl", line 25
at file "/home/cody/.local/bin/../share/openocd/scripts/mem_helper.tcl", line 6

Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 100ms
Info : Previous state query failed, trying to reconnect
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 300ms
Info : Listening on port 3333 for gdb connections
Info : Previous state query failed, trying to reconnect
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 700ms
Info : Previous state query failed, trying to reconnect
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 1500ms
^C
[cody@franklin wrist3]$ sudo ~/.local/bin/openocd -c gdb_port\ 3333 -f board/st_nucleo_f4.cfg
Open On-Chip Debugger 0.10.0+dev-00281-g64f1f7b1-dirty (2018-01-25-14:00)
Licensed under GNU GPL v2
For bug reports, read
http://openocd.org/doc/doxygen/bugs.html
Info : The selected transport took over low-level target control. The results might differ compared to plain JTAG/SWD
adapter speed: 2000 kHz
adapter_nsrst_delay: 100
none separate
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : clock speed 1800 kHz
Info : STLINK v2 JTAG v29 API v2 SWIM v18 VID 0x0483 PID 0x374B
Info : using stlink api v2
Info : Target voltage: 3.250593
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 100ms
Info : Previous state query failed, trying to reconnect
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 300ms
Info : Listening on port 3333 for gdb connections
Info : Previous state query failed, trying to reconnect
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 700ms
Info : Previous state query failed, trying to reconnect
Error: jtag status contains invalid mode value - communication failure
Polling target stm32f4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 1500ms
^C
[cody@franklin wrist3]$ sudo ~/.local/bin/openocd -c gdb_port\ 3333 -f board/st_nucleo_f4.cfg
Open On-Chip Debugger 0.10.0+dev-00281-g64f1f7b1-dirty (2018-01-25-14:00)
Licensed under GNU GPL v2
For bug reports, read
http://openocd.org/doc/doxygen/bugs.html
Info : The selected transport took over low-level target control. The results might differ compared to plain JTAG/SWD
adapter speed: 2000 kHz
adapter_nsrst_delay: 100
none separate
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : clock speed 1800 kHz
Info : STLINK v2 JTAG v29 API v2 SWIM v18 VID 0x0483 PID 0x374B
Info : using stlink api v2
Info : Target voltage: 3.252174
Info : stm32f4x.cpu: hardware has 6 breakpoints, 4 watchpoints
Info : Listening on port 3333 for gdb connections


[Cody Schafer]

I was testing this using a ST Nucleo F429ZI and it's onboard stlink-v2-1, running firmware V2.J29.M18 ( which is shipped with the current STSW-LINK004 4.2.0 as downloaded earlier today).

[Cody Schafer]

I've observed similar behavior with a stm32f407g-disc1.

openocd was connected & streaming data back via itm. stlink usb device was disconnected & then reconnected much later (without killing openocd).

openocd was then killed & restarted, at which point it failed to establish comms until the reset button was held while openocd was started.

log attached. The output at start is from a openocd session that was functional until the stlink usb was unplugged. The last openocd session started was functional again (after holding down the reset button while starting that openocd instance)

[Cody Schafer]

After enabling address sanitizer and ubsan & fixing some reported bugs, the same issue results in a failure to read the stm32, with many register reads resulting in 0xa05f0000 (DBGKEY).

In the output below, the first problem occured numerous times until the reset on the nucleo-f767zi was held down while openocd was started (which is what was done durring the second openocd invocation.

[cody@franklin x]$ UBSAN_OPTIONS=print_stacktrace=1 openocd -f board/st_nucleo_f7.cfg
Open On-Chip Debugger 0.10.0+dev-00327-g919beffc-dirty (2018-03-07-16:28)
Licensed under GNU GPL v2
For bug reports, read
        http://openocd.org/doc/doxygen/bugs.html
Info : The selected transport took over low-level target control. The results might differ compared to plain JTAG/SWD
adapter speed: 2000 kHz
adapter_nsrst_delay: 100
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : clock speed 1800 kHz
Info : STLINK v2 JTAG v28 API v2 SWIM v18 VID 0x0483 PID 0x374B
Info : using stlink api v2
Info : Target voltage: 3.254881
Info : DWT_CTRL: a05f0000
Info : stm32f7x.cpu: hardware has 0 breakpoints, 10 watchpoints
Info : Listening on port 3333 for gdb connections
^C
[cody@franklin x]$ UBSAN_OPTIONS=print_stacktrace=1 openocd -f board/st_nucleo_f7.cfg
Open On-Chip Debugger 0.10.0+dev-00327-g919beffc-dirty (2018-03-07-16:28)
Licensed under GNU GPL v2
For bug reports, read
        http://openocd.org/doc/doxygen/bugs.html
Info : The selected transport took over low-level target control. The results might differ compared to plain JTAG/SWD
adapter speed: 2000 kHz
adapter_nsrst_delay: 100
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : clock speed 1800 kHz
Info : STLINK v2 JTAG v28 API v2 SWIM v18 VID 0x0483 PID 0x374B
Info : using stlink api v2
Info : Target voltage: 3.261214
Info : DWT_CTRL: 40000000
Info : stm32f7x.cpu: hardware has 8 breakpoints, 4 watchpoints
Info : Listening on port 3333 for gdb connections

[Cody Schafer]

Heres some other output from the same error as noted in the comment above. Note that 0xa05f0000 is seen for both DWT_CTRL and the device id.

ody@franklin x]$ UBSAN_OPTIONS=print_stacktrace=1 openocd -f board/st_nucleo_f7.cfg
Open On-Chip Debugger 0.10.0+dev-00327-g919beffc-dirty (2018-03-07-16:16)
Licensed under GNU GPL v2
For bug reports, read
        http://openocd.org/doc/doxygen/bugs.html
Info : The selected transport took over low-level target control. The results might differ compared to plain JTAG/SWD
adapter speed: 2000 kHz
adapter_nsrst_delay: 100
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : clock speed 1800 kHz
Info : STLINK v2 JTAG v28 API v2 SWIM v18 VID 0x0483 PID 0x374B
Info : using stlink api v2
Info : Target voltage: 3.258048
Info : DWT_CTRL: a05f0000
Info : stm32f7x.cpu: hardware has 0 breakpoints, 10 watchpoints
Info : Listening on port 3333 for gdb connections
Info : accepting 'gdb' connection on tcp/3333
Info : device id = 0xa05f0000
Warn : Cannot identify target as a STM32 family.
Error: auto_probe failed
Error: Connect failed. Consider setting up a gdb-attach event for the target to prepare target for GDB connect, or use 'gdb_memory_map disable'.
Error: attempted 'gdb' connection rejected

[Cody Schafer]

I've reproduced this with a seperate stlink-v2 on a stm32f777bit.

Note that the first run shows a strange number of watchpoints & breakpoints.
The second run is done while holding an on-board reset button.

[cody@franklin fb5]$ openocd  -f interface/stlink.cfg -f target/stm32f7x.cfg
Open On-Chip Debugger 0.10.0+dev-00387-gcd89f213-dirty (2018-04-10-09:59)
Licensed under GNU GPL v2
For bug reports, read
        http://openocd.org/doc/doxygen/bugs.html
Info : auto-selecting first available session transport "hla_swd". To override use 'transport select <transport>'.
Info : The selected transport took over low-level target control. The results might differ compared to plain JTAG/SWD
adapter speed: 2000 kHz
adapter_nsrst_delay: 100
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : clock speed 1800 kHz
Info : STLINK v2 JTAG v28 API v2 SWIM v6 VID 0x0483 PID 0x3748
Info : using stlink api v2
Info : Target voltage: 3.208388
Info : stm32f7x.cpu: hardware has 127 breakpoints, 15 watchpoints
Info : Listening on port 3333 for gdb connections
^C
[cody@franklin fb5]$ openocd  -f interface/stlink.cfg -f target/stm32f7x.cfg
Open On-Chip Debugger 0.10.0+dev-00387-gcd89f213-dirty (2018-04-10-09:59)
Licensed under GNU GPL v2
For bug reports, read
        http://openocd.org/doc/doxygen/bugs.html
Info : auto-selecting first available session transport "hla_swd". To override use 'transport select <transport>'.
Info : The selected transport took over low-level target control. The results might differ compared to plain JTAG/SWD
adapter speed: 2000 kHz
adapter_nsrst_delay: 100
srst_only separate srst_nogate srst_open_drain connect_deassert_srst
Info : Listening on port 6666 for tcl connections
Info : Listening on port 4444 for telnet connections
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : Unable to match requested speed 2000 kHz, using 1800 kHz
Info : clock speed 1800 kHz
Info : STLINK v2 JTAG v28 API v2 SWIM v6 VID 0x0483 PID 0x3748
Info : using stlink api v2
Info : Target voltage: 3.211534
Info : stm32f7x.cpu: hardware has 8 breakpoints, 4 watchpoints
Info : Listening on port 3333 for gdb connections

This openocd is slightly modified from be87994d60457ac846740dd9e5df3c8f63cf646e to silence some ubsan warnings.

[Paul Fertser]

Hi,

On Tue, Apr 10, 2018 at 08:42:46PM -0000, Cody Schafer wrote:

Note that the first run shows a strange number of watchpoints & breakpoints.
The second run is done while holding an on-board reset button.

Does reset_config "srst_only connect_assert_srst" (obviously with SRST
connected to the debugger) help?

--
Be free, use free (http://www.gnu.org/philosophy/free-sw.html) software!
mailto:fercerpav@gmail.com

[Cody Schafer]

After observing the strange number of breakpoints/watchpoints, using:

openocd -f interface/stlink.cfg -c 'reset_config srst_only connect_assert_srst' -f target/stm32f7x.cfg

To connect with openocd appears to connect correctly (correct number of breakpoints/watchpoints).

However, when I then connect gdb to openocd to load an image, openocd hangs and notes:

Info : Listening on port 3333 for gdb connections
Info : accepting 'gdb' connection on tcp/3333
Info : Halt timed out, wake up GDB.
Error: timed out while waiting for target halted
jim.c:6169:5: runtime error: null pointer passed as argument 1, which is declared to never be null
jim.c:6169:5: runtime error: null pointer passed as argument 2, which is declared to never be null

Info : device id = 0x10016451
Warn : STM32 flash size failed, probe inaccurate - assuming 2048k flash
Info : flash size = 2048kbytes
Error: auto_probe failed
Error: Connect failed. Consider setting up a gdb-attach event for the target to prepare target for GDB connect, or use 'gdb_memory_map disable'.
Error: attempted 'gdb' connection rejected
^C

At the end, gdb is kicked out:

Reading symbols from _b/fb5...done.
.gdbinit:1: Error in sourced command file:
Remote communication error.  Target disconnected.: Connection reset by peer.
(gdb) quit

Line 1 of .gdbinit is target extended-remote :3333.

Using the "hold reset button while starting openocd" workaround gets us fully functional (can load a program).