Debugging ULP_RISCV on ESP32S2

[scottsh]

I'm having some trouble debugging problems with my ULP_RISCV program. I've got some memory based logging set up, so I can see things back in the host when the host is running, but I keep getting ULP_RISCV crashes, (Wake up code ESP_SLEEP_WAKEUP_COCPU_TRAP_TRIG), and can't figure out how to debug them.

1) Is there a way to get JTAG access to the ULP_RISCV? I don't see it enumerated over OpenOCD as a tap. The only tap I see is the Xtensa core. Is there a different JTAG interface?
2) Is there an exception record generated somewhere? Stored in memory at a magic location?
3) How is that ESP_SLEEP_WAKEUP_COCPU_TRAP_TRIG generated?
4) Is there a way to add an exception handler in my ULP program?

My guess is that the ULP_RISCV exception happens when the Xtensa core enters deep sleep. It initializes testval to 8, but when the ulp exception happens, testval=16, which means that the ulp ran and woke up 8 times, getting the value up to 16. With a 20ms timer, that should have taken 160ms. The only code that the RISCV should be running at that time is the increment and the compare.

For reference, my ULP_RISCV program is the essence of simplicity:

Code: Select all

#include "ulp_riscv/ulp_riscv.h"
#include "ulp_riscv/ulp_riscv_utils.h"

int testval = 8;

int main (void)
{
    testval++;

    if(testval % 100 == 0)
    {
        // Wakeup main CPU
        ulp_riscv_wakeup_main_processor();
    } 

    return 0;
}

The code for the Xtensa is similarly simple:

Code: Select all

/* ULP riscv example

   This example code is in the Public Domain (or CC0 licensed, at your option.)

   Unless required by applicable law or agreed to in writing, this
   software is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR
   CONDITIONS OF ANY KIND, either express or implied.
*/

#include <stdio.h>
#include "esp_sleep.h"
#include "esp_log.h"
#include "soc/rtc_cntl_reg.h"
#include "esp32s2/ulp.h"
#include "esp32s2/ulp_riscv.h"
#include "ulp_main.h"
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "soc/sens_reg.h"

static const char *TAG = "ULP_RISCV";

extern const uint8_t ulp_main_bin_start[] asm("_binary_ulp_main_bin_start");
extern const uint8_t ulp_main_bin_end[]   asm("_binary_ulp_main_bin_end");

static void init_ulp_program(void);

void app_main(void)
{
    printf("top ulp_testval=%d\n", ulp_testval);
    esp_sleep_wakeup_cause_t cause = esp_sleep_get_wakeup_cause();
    switch (cause)
    {
        case ESP_SLEEP_WAKEUP_ULP:
            printf("ULP wakeup\n");
            printf("ulp_testval=%d\n", ulp_testval);
            break;

        case ESP_SLEEP_WAKEUP_COCPU_TRAP_TRIG:
            printf("COCPU TRAP! Reinitializing ULP\n");
            init_ulp_program();
            break;

        default:
            printf("Unknown wakeup (%d), initializing ULP\n", cause);
            init_ulp_program();
            break;
    }

    ESP_LOGI(TAG, "Enabling ulp wakeup");
    ESP_ERROR_CHECK( esp_sleep_enable_ulp_wakeup() );

    // suppress boot messages
    esp_deep_sleep_disable_rom_logging(); 

    printf("Entering deep sleep ulp_testval=%d\n\n", ulp_testval);

    esp_deep_sleep_start();

}

static void init_ulp_program(void)
{
    esp_err_t err = ulp_riscv_load_binary(ulp_main_bin_start, (ulp_main_bin_end - ulp_main_bin_start));
    ESP_ERROR_CHECK(err);

    /* The first argument is the period index, which is not used by the ULP-RISC-V timer
     * The second argument is the period in microseconds, which gives a wakeup time period of: 20ms
     */
    ulp_set_wakeup_period(0, 20000);

    /* Start the program */
    err = ulp_riscv_run();
    ESP_ERROR_CHECK(err);
}

The output it prints is

ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6100,len:0x8
load:0x3ffe6108,len:0x12a8
load:0x4004c000,len:0x8c4
load:0x40050000,len:0x2c34
entry 0x4004c1a8
top ulp_testval=2008032767
Unknown wakeup (0), initializing ULP
Entering deep sleep ulp_testval=8

ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x5 (DSLEEP),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6100,len:0x8
load:0x3ffe6108,len:0x12a8
load:0x4004c000,len:0x8c4
load:0x40050000,len:0x2c34
entry 0x4004c1a8
top ulp_testval=16
COCPU TRAP! Reinitializing ULP
Entering deep sleep ulp_testval=8

ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x5 (DSLEEP),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6100,len:0x8
load:0x3ffe6108,len:0x12a8
load:0x4004c000,len:0x8c4
load:0x40050000,len:0x2c34
entry 0x4004c1a8
top ulp_testval=16
COCPU TRAP! Reinitializing ULP
Entering deep sleep ulp_testval=8

The first wakeup at the top is the cold boot where it initializes the ULP.
Every other wakeup after that is COCPU Trap. The testval when the cocpu trap occurs is 16, indicating that the ULP has woken up 8 times, for a theoretical time of 160ms. Not sure how long the Xtensa takes to really go to sleep after initializing the ULP, but that does sound a little long...

Appreciate any advice or help.

Thanks,

- Scott

[felmue]

Hello @scottsh

I don't have any information / idea about how to debug ULP_RISCV except with trial and error - so sorry about that. But I can share my findings with the ULP_RISCV - which seems to be buggy still.

In my experience the wakeup period

Code: Select all

ulp_set_wakeup_period(0, 20000);

doesn't work (yet). Well, at least not while the main CPU is in deep sleep.

And if you look at the stock ULP_RISCV example you'll notice that the ULP processor is kept in a while loop and only exits after waking the main CPU.

BTW: Using a while loop with your ULP_RISCV code works for me - no more ESP_SLEEP_WAKEUP_COCPU_TRAP_TRIG.

Code: Select all

/* ULP-RISC-V example

   This example code is in the Public Domain (or CC0 licensed, at your option.)

   Unless required by applicable law or agreed to in writing, this
   software is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR
   CONDITIONS OF ANY KIND, either express or implied.

   This code runs on ULP-RISC-V  coprocessor
*/

#include <stdio.h>
#include <stdint.h>
#include <stdbool.h>
#include "ulp_riscv/ulp_riscv.h"
#include "ulp_riscv/ulp_riscv_utils.h"
#include "example_ulp_gpio.h"

static bool gpio_level = false;

/* this variable will be exported as a public symbol, visible from main CPU: */
bool gpio_level_previous = false;

int main (void)
{
    gpio_level = (bool)example_ulp_gpio_get_level(GPIO_NUM_0);
    gpio_level_previous = gpio_level;

    while(1) {
        gpio_level = (bool)example_ulp_gpio_get_level(GPIO_NUM_0);

        /* Wakes up the main CPU if pin changed its state */
        if(gpio_level != gpio_level_previous) {
            gpio_level_previous = gpio_level;
            ulp_riscv_wakeup_main_processor();
            break;
        }

    }
    /* ulp_riscv_shutdown() is called automatically when main exits */
    return 0;
}

Thanks
Felix

[boarchuz]

SENS_SAR_COCPU_DEBUG_REG might be helpful. Set SENS_SAR_COCPU_STATE_REG[SENS_COCPU_DBG_TRIGGER] to update (I'm not sure it's immediate though?).

For this specific one, try:

• Call esp_sleep_pd_config(ESP_PD_DOMAIN_RTC_PERIPH, ESP_PD_OPTION_ON) before esp_deep_sleep_start
• Remove REG_SET_FIELD(RTC_CNTL_COCPU_CTRL_REG, RTC_CNTL_COCPU_SHUT_2_CLK_DIS, 0x3F) from ulp_riscv_shutdown
• Wrap your ulp program in ulp_riscv_rescue_from_monitor and ulp_riscv_shutdown

It works fine when I do all of those things but my project folder is a bit of a mess now so I'm not sure if there's been a IDF regression or I've messed up my settings.

[scottsh]

Thanks @boarchuz! Your suggestions really helped! I got the simple example working pretty well and decided to go back to my full app (much bigger).

I feel like I'm getting a lot closer, but I am still getting spurious exceptions when my code isn't running. I have a bunch of logging in my code and I can see that one run through the ULP_RISCV completed and the next one hasn't started yet, and I still wake up with an exception... I'm guessing that it's when the ULP_RISCV is trying to start up or shutdown, it's crashing.

I've got my timer set to 1 second (@felmue: the timer does appear to work now. I was seeing the same as you, but after the suggestions from @boarchuz I am seeing the wake up timer work correctly now even when the Xtensa core is in deep sleep.), and I'm seeing my loop run between 1 and ~11 times before I hit the exception.

I'm very intrigued by the register you pointed to, but I can't find it documented in the ESP32S2 technical reference manual, and can't find it mentioned anywhere except in sens_reg.h. (Google doesn't even find that reference! )
Do you know where I can find any documentation or samples on how those registers are used?
I set the trigger bit before I enabled the ULP (and again before I read it), and the PC always seems to to be on one of two instructions which are the last register set in ulp_riscv_shutdown (which is supposed to reset the CPU), before the while(1) loop.

**************************************************************
* FUNCTION *
**************************************************************
undefined ulp_riscv_shutdown()
undefined a0:1 <RETURN>
ulp_riscv_shutdown XREF[3]: Entry Point(*), 0000001e(c),
main:0000032c(c)
0000038e a1 67 c.lui a5,0x8
00000390 03 a7 07 10 lw a4,0x100(a5=>DAT_00008100)
00000394 b7 06 00 01 lui a3,0x1000
00000398 55 8f c.or a4,a3
0000039a 23 a0 e7 10 sw a4,0x100(a5=>DAT_00008100)
0000039e 03 a7 07 10 lw a4,0x100(a5=>DAT_00008100)
000003a2 b7 06 00 02 lui a3,0x2000
000003a6 55 8f c.or a4,a3
000003a8 23 a0 e7 10 sw a4,0x100(a5=>DAT_00008100)
000003ac 03 a7 07 10 lw a4,0x100(a5=>DAT_00008100)
000003b0 b7 06 40 00 lui a3,0x400
000003b4 55 8f c.or a4,a3
000003b6 23 a0 e7 10 sw a4,0x100(a5=>DAT_00008100)
LAB_000003ba XREF[1]: 000003ba(j)
000003ba 01 a0 c.j LAB_000003ba

Usually seems to be one of these three values:
I (485) ULP: SENS_SAR_COCPU_DEBUG_REG=0x196783b6
I (485) ULP: SENS_SAR_COCPU_DEBUG_REG=0x1da003b4
Once I saw this one, which is the previous instruction:
I (485) ULP: SENS_SAR_COCPU_DEBUG_REG=0x80003b0

Any ideas?

Thanks,

- Scott