search

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.52k stars 6.45k forks source link

Bluetooth: Mesh: Sample is stuck in init process on disco_l475_iot #34268

Closed tobias-mierzwa closed 3 years ago

tobias-mierzwa commented 3 years ago

Describe the bug I was trying to test the mesh sample ${ZEPHYR_BASE}/samples/bluetooth/mesh/. After i build and flashed it on my board, it was working first by pressing the userbutton and turn off/on the led. After i rebuild and flashed it again on the board, without making changes, it stucks in the init flash process.

To Reproduce Steps to reproduce the behavior:

  1. west build -p auto -b disco_l475_iot1 samples/bluetooth/mesh/ -c
  2. west flash

Expected behavior Testing the mesh sample by pressing the userbutton and turn off/on led

Logs and console output

Build logs:

west build -p auto -b disco_l475_iot1 samples/bluetooth/mesh/ -c -DCMAKE_EXPORT_COMPILE_COMMANDS=1
-- west build: generating a build system
Including boilerplate (Zephyr base (cached)): /home/tobias/zephyrproject/zephyr/cmake/app/boilerplate.cmake
-- Application: /home/tobias/zephyrproject/zephyr/samples/bluetooth/mesh
-- Zephyr version: 2.5.99 (/home/tobias/zephyrproject/zephyr)
-- Found west (found suitable version "0.8.0", minimum required is "0.7.1")
-- Board: disco_l475_iot1
-- Cache files will be written to: /home/tobias/.cache/zephyr
-- Using toolchain: zephyr 0.12.3 (/home/tobias/zephyr-sdk-0.12.3)
-- Found dtc: /home/tobias/zephyr-sdk-0.12.3/sysroots/x86_64-pokysdk-linux/usr/bin/dtc (found suitable version "1.5.0", minimum required is "1.4.6")
-- Found BOARD.dts: /home/tobias/zephyrproject/zephyr/boards/arm/disco_l475_iot1/disco_l475_iot1.dts
-- Generated zephyr.dts: /home/tobias/zephyrproject/zephyr/build/zephyr/zephyr.dts
-- Generated devicetree_unfixed.h: /home/tobias/zephyrproject/zephyr/build/zephyr/include/generated/devicetree_unfixed.h
-- Generated device_extern.h: /home/tobias/zephyrproject/zephyr/build/zephyr/include/generated/device_extern.h
Parsing /home/tobias/zephyrproject/zephyr/Kconfig
Loaded configuration '/home/tobias/zephyrproject/zephyr/build/zephyr/.config'
No change to configuration in '/home/tobias/zephyrproject/zephyr/build/zephyr/.config'
No change to Kconfig header in '/home/tobias/zephyrproject/zephyr/build/zephyr/include/generated/autoconf.h'
CMake Deprecation Warning at /home/tobias/zephyrproject/modules/lib/civetweb/CMakeLists.txt:2 (cmake_minimum_required):
  Compatibility with CMake < 2.8.12 will be removed from a future version of
  CMake.

  Update the VERSION argument <min> value or use a ...<max> suffix to tell
  CMake that the project does not need compatibility with older versions.

-- Configuring done
CMake Warning (dev) at ../../../cmake/linker/ld/target.cmake:33 (add_custom_command):
  Policy CMP0116 is not set: Ninja generators transform DEPFILEs from
  add_custom_command().  Run "cmake --help-policy CMP0116" for policy
  details.  Use the cmake_policy command to set the policy and suppress this
  warning.
Call Stack (most recent call first):
  ../../../CMakeLists.txt:1093 (configure_linker_script)
This warning is for project developers.  Use -Wno-dev to suppress it.

CMake Warning (dev) at ../../../cmake/linker/ld/target.cmake:33 (add_custom_command):
  Policy CMP0116 is not set: Ninja generators transform DEPFILEs from
  add_custom_command().  Run "cmake --help-policy CMP0116" for policy
  details.  Use the cmake_policy command to set the policy and suppress this
  warning.
Call Stack (most recent call first):
  ../../../CMakeLists.txt:1039 (configure_linker_script)
This warning is for project developers.  Use -Wno-dev to suppress it.

-- Generating done
-- Build files have been written to: /home/tobias/zephyrproject/zephyr/build
-- west build: building application
[161/167] Linking C executable zephyr/zephyr_prebuilt.elf

[167/167] Linking C executable zephyr/zephyr.elf
Memory region         Used Size  Region Size  %age Used
           FLASH:      173332 B         1 MB     16.53%
            SRAM:       30202 B        96 KB     30.72%
        IDT_LIST:          0 GB         2 KB      0.00%

Flash logs:

west flash
-- west flash: rebuilding
[0/1] cd /home/tobias/zephyrproject/zephyr/build/zephyr/cmake/flash && /usr/bin/cmake -E echo

-- west flash: using runner openocd
-- runners.openocd: Flashing file: /home/tobias/zephyrproject/zephyr/build/zephyr/zephyr.hex
Open On-Chip Debugger 0.10.0+dev-01508-gf79c90268-dirty (2021-02-16-17:45)
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
srst_only separate srst_nogate srst_open_drain connect_deassert_srst

Info : clock speed 500 kHz
Info : STLINK V2J28M18 (API v2) VID:PID 0483:374B
Info : Target voltage: 3.213639
Info : stm32l4x.cpu: hardware 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       halted

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: 0x08003d54 msp: 0x20004420
Info : device idcode = 0x10076415 (STM32L47/L48xx - Rev: 4)
Info : flash size = 1024kbytes
Info : flash mode : dual-bank
Info : Padding image section 0 at 0x0802a514 with 4 bytes (bank write end alignment)
Warn : Adding extra erase range, 0x0802a518 .. 0x0802a7ff
auto erase enabled
wrote 173336 bytes from file /home/tobias/zephyrproject/zephyr/build/zephyr/zephyr.hex in 7.579745s (22.332 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: 0x08003d54 msp: 0x20004420
verified 173332 bytes in 5.053581s (33.495 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

Picocom logs :

*** Booting Zephyr OS build zephyr-v2.5.0-2155-gc7412bb0c46c  ***
Initializing...
[00:00:00.000,000] <inf> flash_stm32_qspi: MX2

Environment:

erwango commented 3 years ago

@Verfuchst Did you make any specific modification before reflashing ? I has a try on my side and it worked fine...

trond-snekvik commented 3 years ago

Same for me. Are you able to try on a non-modified master, and pinpoint where things go wrong with a debugger? Does it get into the bluetooth enable callback?

tobias-mierzwa commented 3 years ago

I tried again on the master commit 36d96d2cd9b9e9f200691e34d053bb8cf52321ca. It stucks in the routine there and calls the function spi_stm32_isr again and again. Screenshot_2021-04-16_16-29-45

erwango commented 3 years ago

One thing to unlock your issue quickly would be to remove zephyr,flash-controller = &mx25r6435f; so you don't use qspi anymore. Does not solve the point but could help.

tobias-mierzwa commented 3 years ago

I tried this with removing the line, but it did not changed anything. Now I'm also stuck in another code section. Its really random so i can try to get the same board next week and see if its something with the hardware.

carlescufi commented 3 years ago

This happens before the Bluetooth subsystem is even initialized, so removing the Bluetooth labels.

tobias-mierzwa commented 3 years ago

Sorry for late respone, it wasnt possible to get as quick as possible the board, because of corona. But i tried the same scenario with the new same board even with the latest commit 4b4068c948ea4fd764df549aedb70d0f698491c3 and i still get the same situtation with stucking in the init process. serial output:

*** Booting Zephyr OS build v2.6.0-rc1-181-g4b4068c948ea  ***
Initializing...
[00:00:00.000,000] <inf> flash_stm32_qspi: MX25

code section: Screenshot_2021-05-18_18-47-11

erwango commented 3 years ago

Ok, that's really strange we're not seeing the same.

Can you have a try by removing use of qspi as flash controller on the board? Basically, you need to: -Remove qspi as flash controller -Re-instantiate storage partition on flash

This is equivalent to revert change (in the board dts file, no need to revert the full driver support) https://github.com/zephyrproject-rtos/zephyr/pull/30864/files#diff-b334b8ae2850c29b634b8dd4678791bcd4731c3319f9fd026839e31b9a354832

tobias-mierzwa commented 3 years ago

Without the qspi i could run the sample, but even there, there was some weird acting. So it just felt like, its still something with the hardware and not your code. I will take a look at this, when i get the time. But for now, i would say we gonna close this issue, till someone has the same kinda problem. And if i get any news and i can say its 100% the hardware, i will leave a comment here.

erwango commented 3 years ago

@Verfuchst Thanks for this feedback. I'm closing the issue then. Feel free to comment or reopen