zephyrproject-rtos / zephyr

Primary Git Repository for the Zephyr Project. Zephyr is a new generation, scalable, optimized, secure RTOS for multiple hardware architectures.
https://docs.zephyrproject.org
Apache License 2.0
10.85k stars 6.61k forks source link

Cannot flash b_l4s5i_iot01a samples/hello_world #54614

Closed jvermillard closed 1 year ago

jvermillard commented 1 year ago

Describe the bug Just getting started with zephyr of this target, I try to follow the doc here: https://docs.zephyrproject.org/latest/boards/arm/b_l4s5i_iot01a/doc/index.html

I can compile, run west flash but my board is still running the previous firmware

To Reproduce

west build -b b_l4s5i_iot01a samples/hello_world
west flash

output:

ninja: no work to do.
-- west flash: rebuilding
ninja: no work to do.
-- west flash: using runner openocd
-- runners.openocd: Flashing file: /home/jvermillard/sandbox/zephyrproject/zephyr/build/zephyr/zephyr.hex
Open On-Chip Debugger 0.11.0+dev-00725-gc5c47943d (2022-11-22-06:32)
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
Info : clock speed 500 kHz
Info : STLINK V2J28M18 (API v2) VID:PID 0483:374B
Info : Target voltage: 3.220513
Info : [stm32l4x.cpu] Cortex-M4 r0p1 processor detected
Info : [stm32l4x.cpu] target has 6 breakpoints, 4 watchpoints
Info : starting gdb server for stm32l4x.cpu on 3333
Info : Listening on port 3333 for gdb connections
    TargetName         Type       Endian TapName            State       
--  ------------------ ---------- ------ ------------------ ------------
 0* stm32l4x.cpu       hla_target little stm32l4x.cpu       running

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
target halted due to debug-request, current mode: Thread 
xPSR: 0x01000000 pc: 0x1fff51da msp: 0x20003560
Info : device idcode = 0x100f6470 (STM32L4R/L4Sxx - Rev W : 0x100f)
Info : RDP level 0 (0xAA)
Info : flash size = 2048kbytes
Info : flash mode : dual-bank
Info : Padding image section 0 at 0x08003504 with 4 bytes (bank write end alignment)
Warn : Adding extra erase range, 0x08003508 .. 0x08003fff
auto erase enabled
wrote 13576 bytes from file /home/jvermillard/sandbox/zephyrproject/zephyr/build/zephyr/zephyr.hex in 0.750638s (17.662 KiB/s)

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
target halted due to debug-request, current mode: Thread 
xPSR: 0x01000000 pc: 0x1fff51da msp: 0x20003560
verified 13572 bytes in 0.434468s (30.506 KiB/s)

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
shutdown command invoked

Expected behavior The board running hello world and seeing the default message on the console

Environment (please complete the following information):

jvermillard commented 1 year ago

Forgot some details. Even after resetting the board, I don't have any other message on the UART console than:

STM32L4XX Lib:
> CMSIS Device Version: 1.7.0.0.
> HAL Driver Version: 1.12.0.0.
> BSP Driver Version: 1.0.0.0.
ES-WIFI Firmware:
> Product Name: Inventek eS-WiFi
> Product ID: ISM43362-M3G-L44-SPI
> Firmware Version: C3.5.2.5.STM
> API Version: v3.5.2
ES-WIFI MAC Address: C4:7F:51:94:4A:52
!!!ERROR: ES-WIFI NOT connected.
dns_create fail: 67

Which, I believe, is generated by the old firmware

erwango commented 1 year ago

Working on my side:

ninja: no work to do.
-- west flash: using runner openocd
-- runners.openocd: Flashing file: build/b_l4s5i_iot01a/zephyr/zephyr.hex
Open On-Chip Debugger 0.11.0+dev-00725-gbbc647536 (2022-09-29-05:05)
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
Info : clock speed 500 kHz
Info : STLINK V2J36M26 (API v2) VID:PID 0483:374B
Info : Target voltage: 3.239526
Warn : target stm32l4x.cpu examination failed
Error: jtag status contains invalid mode value - communication failure
Polling target stm32l4x.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 stm32l4x.cpu failed, trying to reexamine
Examination failed, GDB will be halted. Polling again in 300ms
Info : starting gdb server for stm32l4x.cpu on 3333
Info : Listening on port 3333 for gdb connections
    TargetName         Type       Endian TapName            State       
--  ------------------ ---------- ------ ------------------ ------------
 0* stm32l4x.cpu       hla_target little stm32l4x.cpu       unknown

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
Error: read_memory: read at 0xe0042004 with width=32 and count=1 failed
Error executing event examine-end on target stm32l4x.cpu:
/local/mcu/zephyrproject/sdk/zephyr-sdk-0.15.1-rc1-1-g3ff4618/sysroots/x86_64-pokysdk-linux/usr/share/openocd/scripts/mem_helper.tcl:5: Error: read_memory: failed to read memory
in procedure 'ocd_process_reset' 
in procedure 'ocd_process_reset_inner' called at file "embedded:startup.tcl", line 876
in procedure 'mmw' called at file "/local/mcu/zephyrproject/sdk/zephyr-sdk-0.15.1-rc1-1-g3ff4618/sysroots/x86_64-pokysdk-linux/usr/share/openocd/scripts/target/stm32l4x.cfg", line 97
in procedure 'mrw' called at file "/local/mcu/zephyrproject/sdk/zephyr-sdk-0.15.1-rc1-1-g3ff4618/sysroots/x86_64-pokysdk-linux/usr/share/openocd/scripts/mem_helper.tcl", line 30
at file "/local/mcu/zephyrproject/sdk/zephyr-sdk-0.15.1-rc1-1-g3ff4618/sysroots/x86_64-pokysdk-linux/usr/share/openocd/scripts/mem_helper.tcl", line 5
Info : Previous state query failed, trying to reconnect
target halted due to debug-request, current mode: Thread 
xPSR: 0x01000000 pc: 0x0800455c msp: 0x20001958
Polling target stm32l4x.cpu failed, trying to reexamine
Info : [stm32l4x.cpu] Cortex-M4 r0p1 processor detected
Info : [stm32l4x.cpu] target has 6 breakpoints, 4 watchpoints
Info : device idcode = 0x100f6470 (STM32L4R/L4Sxx - Rev W : 0x100f)
Info : RDP level 0 (0xAA)
Info : flash size = 2048kbytes
Info : flash mode : dual-bank
Warn : Adding extra erase range, 0x08003740 .. 0x08003fff
auto erase enabled
wrote 14144 bytes from file build/b_l4s5i_iot01a/zephyr/zephyr.hex in 0.379996s (36.349 KiB/s)

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
target halted due to debug-request, current mode: Thread 
xPSR: 0x01000000 pc: 0x080010f0 msp: 0x20000fd8
verified 14144 bytes in 0.093471s (147.773 KiB/s)

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
shutdown command invoked

There are some errors, this isn't a walk in the park, but it eventually succeeds.

*** Booting Zephyr OS build v3.3.0-rc1-6-g7e9a0e851eb7 ***
Hello World! b_l4s5i_iot01a

Also, on your side, according to the log, it looks like it actually succeeds:

wrote 13576 bytes from file /home/jvermillard/sandbox/zephyrproject/zephyr/build/zephyr/zephyr.hex in 0.750638s (17.662 KiB/s)
verified 13572 bytes in 0.434468s (30.506 KiB/s)

Looks actually odd that console output isn't matching.

erwango commented 1 year ago

One suggestion would be to update ST-Link version.

For unknown reason, I was not using latest SDK. Here is the log with SDK-0.15.2, using exact same version for openocd:

ninja: no work to do.
-- west flash: using runner openocd
-- runners.openocd: Flashing file: build/b_l4s5i_iot01a/zephyr/zephyr.hex
Open On-Chip Debugger 0.11.0+dev-00725-gc5c47943d (2022-11-22-06:32)
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
Info : clock speed 500 kHz
Info : STLINK V2J36M26 (API v2) VID:PID 0483:374B
Info : Target voltage: 3.242688
Info : [stm32l4x.cpu] Cortex-M4 r0p1 processor detected
Info : [stm32l4x.cpu] target has 6 breakpoints, 4 watchpoints
Info : starting gdb server for stm32l4x.cpu on 3333
Info : Listening on port 3333 for gdb connections
    TargetName         Type       Endian TapName            State       
--  ------------------ ---------- ------ ------------------ ------------
 0* stm32l4x.cpu       hla_target little stm32l4x.cpu       running

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
target halted due to debug-request, current mode: Thread 
xPSR: 0x01000000 pc: 0x080010f0 msp: 0x20000fd8
Info : device idcode = 0x100f6470 (STM32L4R/L4Sxx - Rev W : 0x100f)
Info : RDP level 0 (0xAA)
Info : flash size = 2048kbytes
Info : flash mode : dual-bank
Warn : Adding extra erase range, 0x08003740 .. 0x08003fff
auto erase enabled
wrote 14144 bytes from file build/b_l4s5i_iot01a/zephyr/zephyr.hex in 0.380564s (36.295 KiB/s)

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
target halted due to debug-request, current mode: Thread 
xPSR: 0x01000000 pc: 0x080010f0 msp: 0x20000fd8
verified 14144 bytes in 0.091746s (150.552 KiB/s)

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
shutdown command invoked
jvermillard commented 1 year ago

BTW my jumper configuration: image

Also I upgraded my stlink using the IDE: image

still the same issue, west flash logs:

❯ west flash                                                                                                                                                                                     zephyr/git/main 
-- west flash: rebuilding
ninja: no work to do.
-- west flash: using runner openocd
-- runners.openocd: Flashing file: /home/jvermillard/sandbox/zephyrproject/zephyr/build/zephyr/zephyr.hex
Open On-Chip Debugger 0.11.0+dev-00725-gc5c47943d (2022-11-22-06:32)
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
Info : clock speed 500 kHz
Info : STLINK V2J39M27 (API v2) VID:PID 0483:374B
Info : Target voltage: 3.220513
Info : [stm32l4x.cpu] Cortex-M4 r0p1 processor detected
Info : [stm32l4x.cpu] target has 6 breakpoints, 4 watchpoints
Info : starting gdb server for stm32l4x.cpu on 3333
Info : Listening on port 3333 for gdb connections
    TargetName         Type       Endian TapName            State       
--  ------------------ ---------- ------ ------------------ ------------
 0* stm32l4x.cpu       hla_target little stm32l4x.cpu       running

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
target halted due to debug-request, current mode: Thread 
xPSR: 0x01000000 pc: 0x1fff51da msp: 0x20003560
Info : device idcode = 0x100f6470 (STM32L4R/L4Sxx - Rev W : 0x100f)
Info : RDP level 0 (0xAA)
Info : flash size = 2048kbytes
Info : flash mode : dual-bank
Info : Padding image section 0 at 0x08003504 with 4 bytes (bank write end alignment)
Warn : Adding extra erase range, 0x08003508 .. 0x08003fff
auto erase enabled
wrote 13576 bytes from file /home/jvermillard/sandbox/zephyrproject/zephyr/build/zephyr/zephyr.hex in 0.787481s (16.836 KiB/s)

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
target halted due to debug-request, current mode: Thread 
xPSR: 0x01000000 pc: 0x1fff51da msp: 0x20003560
verified 13572 bytes in 0.460189s (28.801 KiB/s)

Info : Unable to match requested speed 500 kHz, using 480 kHz
Info : Unable to match requested speed 500 kHz, using 480 kHz
shutdown command invoked
erwango commented 1 year ago

BTW my jumper configuration:

Looks ok.

Did you try to fully erase flash using STM32CubeProgrammer ? You can even try to flash using STM32CubeProgrammer:

board_runner_args(stm32cubeprogrammer "--port=swd" "--reset-mode=hw")

include(${ZEPHYR_BASE}/boards/common/stm32cubeprogrammer.board.cmake)

This should be put before:

include(${ZEPHYR_BASE}/boards/common/openocd.board.cmake)
jvermillard commented 1 year ago

I erased the flash using stm32cbueide and:

Hello World! b_l4s5i_iot01a

:tada: thanks for the help

kartben commented 1 year ago

That's an interesting one. As I'm assuming others might be bitten by it too, it might be worth updating the doc? And I guess it might be happening with other devkits?

erwango commented 1 year ago

That's an interesting one. As I'm assuming others might be bitten by it too, it might be worth updating the doc? And I guess it might be happening with other devkits?

Actually, it's rather unusual. But yes it would potentially apply to most ST STM32 platforms. This being said, rather than documenting it in each board documentation, what would be great is to have a kind of vendor doc section, in which we can centralize this kind of generic topic (and redirect from boards docs). We've discussed this, but never made it happen, this would be more than welcome ;-)

erwango commented 1 year ago

I erased the flash using stm32cbueide and:

Thanks for updating us. I'm closing the issue