RIOT-OS / RIOT

RIOT - The friendly OS for IoT
https://riot-os.org
GNU Lesser General Public License v2.1
4.88k stars 1.98k forks source link

tests/driver_sx127x problem #11838

Closed isavitsky closed 5 years ago

isavitsky commented 5 years ago

Description

tests/driver_sx127x hangs during the SPI exchange with RFM96 rev. 1.2 (RF98) 433 MHz module on Nucleo-L432KC board.

Steps to reproduce the issue

1) Connect the RFM96 module to the Nucleo-L432KC board in the following configuration:

  GND -> GND
 3.3V -> 3V3
 MISO -> D12
 MOSI -> D11
  SCK -> D13
  NSS -> D10
RESET -> A0
 DIO0 -> D2

2) Specify BOARD and CFLAGS in the Makefile:

BOARD ?= nucleo-l432kc
# SPI1_CS (NSS)       /* D10, PA11 */
CFLAGS+= -DSX127X_PARAM_SPI_NSS="GPIO_PIN(0,11)"

3) Connect the Nucleo board to the USB and start the terminal. 4) cd into tests/driver_sx127x directory and do

make flash

Expected results

The tests/driver_sx127x should build flawlessly and the command shell should start.

Actual results

Actual results are that the test programme is starting the RFM96 module initialisation and then hanging in the middle of an SPI exchange. Here is the full terminal output with DEBUG enabled (additional debug printouts added to track down the failure step):

main(): This is RIOT! (Version: 2019.10-devel-25-g6b094)
[sx127x] netdev: initializing driver...
[sx127x] SPI_0 initialized with success
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 42 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() RX (len: 1): 12 
            wait_for_end()
    spi_release()
[sx127x] SX1276 transceiver detected
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 09 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() RX (len: 1): 4F 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 06 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() RX (len: 1): 6C 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 07 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() RX (len: 1): 80 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 08 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() RX (len: 1): 00 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 89 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 00 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 3B 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() RX (len: 1): 82 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): BB 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): C2 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 3B 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() RX (len: 1): 82 
            wait_for_end()
    spi_release()
[sx127x] Set channel: 868000000
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 86 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): D9 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 87 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 00 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 88 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 00 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 3B 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() RX (len: 1): 82 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): BB 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): C2 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 3B 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() RX (len: 1): 82 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 89 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 4F 
            wait_for_end()
    spi_release()
[sx127x] Set channel: 434000000
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 86 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 6C 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 87 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 80 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 88 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 00 
            wait_for_end()
    spi_release()
[sx127x] Set op mode: SLEEP
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 01 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() RX (len: 1): 09 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 81 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 08 
            wait_for_end()
    spi_release()
[sx127x] initializing radio settings
[sx127x] Set channel: 868300000
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 86 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): D9 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 87 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 13 
            wait_for_end()
    spi_release()
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 88 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 33 
            wait_for_end()
    spi_release()
[sx127x] set modem: 1
    spi_acquire()
    spi_transfer_bytes()
        now call transfer_no_dma():
        transfer_no_dma() TX (len: 1): 01 
            wait_for_end()
    spi_transfer_bytes()
        now call transfer_no_dma():

As far as we can see, the sx127x driver is been able to find out the chip version (0x12) and then in the last few lines we observe that the sx127x driver is going to set modem 1. At first the SPI read register 0x01 command was sent, then spi_transfer_bytes() have to read the result by calling the _transfer_no_dma() function which never happens.

Please, help me find out what I'm missing here to make this test working. Thanks, Ivan

Versions


Operating System Environment
-----------------------------
       Operating System: "Linux Mint" "18.3 (Sylvia)"
                 Kernel: Linux 4.13.0-45-generic x86_64 x86_64

Installed compiler toolchains
-----------------------------
             native gcc: gcc (Ubuntu 5.4.0-6ubuntu1~16.04.11) 5.4.0 20160609
      arm-none-eabi-gcc: arm-none-eabi-gcc (GNU Tools for Arm Embedded Processors 7-2018-q3-update) 7.3.1 20180622 (release) [ARM/embedded-7-branch revision 261907]
                avr-gcc: missing
       mips-mti-elf-gcc: missing
             msp430-gcc: missing
   riscv-none-embed-gcc: missing
   xtensa-esp32-elf-gcc: missing
   xtensa-lx106-elf-gcc: xtensa-lx106-elf-gcc (crosstool-NG crosstool-ng-1.22.0-60-g37b07f6) 4.8.5
                  clang: missing

Installed compiler libs
-----------------------
   arm-none-eabi-newlib: "3.0.0"
    mips-mti-elf-newlib: missing
riscv-none-embed-newlib: missing
xtensa-esp32-elf-newlib: missing
xtensa-lx106-elf-newlib: "2.0.0"
               avr-libc: missing (missing)

Installed development tools
---------------------------
                  cmake: cmake version 3.5.1
               cppcheck: missing
                doxygen: 1.8.11
                 flake8: missing
                    git: git version 2.7.4
                   make: GNU Make 4.1
                openocd: Open On-Chip Debugger 0.10.0
                 python: Python 2.7.12
                python2: Python 2.7.12
                python3: Python 3.5.2
             coccinelle: missing
PeterKietzmann commented 5 years ago

@jia200x, @leandrolanzieri can you reproduce that? Wasn't there something strange with DMA?

leandrolanzieri commented 5 years ago

This board does not have any DMA defined for the SPI transfers so it should not be the problem. I will try to reproduce this.

jia200x commented 5 years ago

hi @isavitsky

We tried the same hardware (RFM96) with a similar nucleo board and couldn't reproduce the issue. Unfortunately we don't have the nucleo-L432KC here (maybe @fjmolinas or @aabadie ?)

Do you know if the function "_transfer_no_dma" is being called? Maybe it will help us if you add some debug messages in around here and inside these while loops. Let us know how that goes.

fjmolinas commented 5 years ago

@isavitsky

I don't have the same radio module as you do, but I do have the same BOARD. I'm able to reproduce while using another radio. I'll try to find out the reason.

fjmolinas commented 5 years ago

@isavitsky I found the issue, the problem comes from the fact that the default pin configuration for the sx127x driver is for nucleo-64 boards, for nucleo-32 board like the nucleo-l432kc the pinout between the Dx and Ax is not the same.

You can apply this diff so the arduino pin mapping match nucleo-32 boards (it worked for me using a nucleo-l432kc and a SX1272MB2xAS):

diff --git a/drivers/sx127x/include/sx127x_params.h b/drivers/sx127x/include/sx127x_params.h
index 661c37e80..7a5074bf7 100644
--- a/drivers/sx127x/include/sx127x_params.h
+++ b/drivers/sx127x/include/sx127x_params.h
@@ -37,27 +37,27 @@ extern "C" {
 #endif

 #ifndef SX127X_PARAM_SPI_NSS
-#define SX127X_PARAM_SPI_NSS                GPIO_PIN(1, 6)       /* D10 */
+#define SX127X_PARAM_SPI_NSS                GPIO_PIN(PORT_A, 11)       /* D10 */
 #endif

 #ifndef SX127X_PARAM_RESET
-#define SX127X_PARAM_RESET                  GPIO_PIN(0, 0)       /* A0 */
+#define SX127X_PARAM_RESET                  GPIO_PIN(PORT_A, 0)       /* A0 */
 #endif

 #ifndef SX127X_PARAM_DIO0
-#define SX127X_PARAM_DIO0                   GPIO_PIN(0, 10)      /* D2 */
+#define SX127X_PARAM_DIO0                   GPIO_PIN(PORT_A, 12)      /* D2 */
 #endif

 #ifndef SX127X_PARAM_DIO1
-#define SX127X_PARAM_DIO1                   GPIO_PIN(1, 3)       /* D3 */
+#define SX127X_PARAM_DIO1                   GPIO_PIN(PORT_B, 0)       /* D3 */
 #endif

 #ifndef SX127X_PARAM_DIO2
-#define SX127X_PARAM_DIO2                   GPIO_PIN(1, 5)       /* D4 */
+#define SX127X_PARAM_DIO2                   GPIO_PIN(PORT_B, 7)       /* D4 */
 #endif

 #ifndef SX127X_PARAM_DIO3
-#define SX127X_PARAM_DIO3                   GPIO_PIN(1, 4)       /* D5 */
+#define SX127X_PARAM_DIO3                   GPIO_PIN(PORT_B, 6)       /* D5 */
 #endif

 #ifndef SX127X_PARAM_PASELECT

image

Let me know if that works for you.

isavitsky commented 5 years ago

Hello team,

Thank you for your replies. @fjmolinas, your diff worked! I had to do it myself, by looking further into the spi.c code. But in my case I have only DIO0 is connected and I didn't bother to check what other DIOs are doing. I substituted the SPI pin defines in sx127x_params.h up to DIO0 define. As @jia200x mentioned, the looping occurs in cpu/stm32_common/periph/spi.c line 239 in waiting for RXNE. Looks like the SPI clock is stopped in the middle of the transfer leading to the flag rise never occurs. Unfortunately I don't have the logic analyser to look deeper in what's going on on the hardware level.

Thanks again, Ivan

fjmolinas commented 5 years ago

@isavitsky

Thank you for your replies. @fjmolinas, your diff worked!

As @jia200x mentioned, the looping occurs in cpu/stm32_common/periph/spi.c line 239 in waiting for RXNE. Looks like the SPI clock is stopped in the middle of the transfer leading to the flag rise never occurs. Unfortunately I don't have the logic analyser to look deeper in what's going on on the hardware level.

Hi Ivan, your two answers got me confused, is the issue fixed for you or still present?

isavitsky commented 5 years ago

Hi @fjmolinas,

Sorry, for not being clear. Without the patch the looping occurs at line 239 in cpu/stm32_common/periph/spi.c.

With patch applied the app works perfectly! I'm now able to query the RFM96 module and issue commands.

Ivan.

jia200x commented 5 years ago

Great! I will close the issue then