drivers: spi: esp32: Continue configuration if SPI clock already running

[jurenat]

This PR attempts to fix the issue with the SPI clock that is present after e282b0e changes to the clock_control_esp32.c.

[sylvioalves]

@LucasTambor Can you take a look whether this issue also exists in other peripherals?

[LucasTambor]

@darkmoon32 Thanks for the PR.

The clock control does expect the -EALREADY error if we try to enable an already enabled clock for a given subsystem.

The correct way would be to use clock_control_on when initialising the driver in spi_esp32_init instead of spi_esp32_configure

Would you mind moving the clock initialisation to the init function? For that to work we should also disable and clear the interrupt status for the SPI peripheral before allocating it's interrupt.

Here's the diff that worked for me:

diff --git a/drivers/spi/spi_esp32_spim.c b/drivers/spi/spi_esp32_spim.c
index d209fd85b04..44ac641eb90 100644
--- a/drivers/spi/spi_esp32_spim.c
+++ b/drivers/spi/spi_esp32_spim.c
@@ -216,16 +216,33 @@ static int spi_esp32_init(const struct device *dev)
 	int err;
 	const struct spi_esp32_config *cfg = dev->config;
 	struct spi_esp32_data *data = dev->data;
+	spi_hal_context_t *hal = &data->hal;
 
 	if (!cfg->clock_dev) {
 		return -EINVAL;
 	}
 
+	if (!device_is_ready(cfg->clock_dev)) {
+		LOG_ERR("clock control device not ready");
+		return -ENODEV;
+	}
+
+	/* enables SPI peripheral */
+	if (clock_control_on(cfg->clock_dev, cfg->clock_subsys)) {
+		LOG_ERR("Could not enable SPI clock");
+		return -EIO;
+	}
+
+	spi_ll_master_init(hal->hw);
+
 	if (cfg->dma_enabled) {
 		spi_esp32_init_dma(dev);
 	}
 
 #ifdef CONFIG_SPI_ESP32_INTERRUPT
+	spi_ll_disable_int(cfg->spi);
+	spi_ll_clear_int_stat(cfg->spi);
+
 	data->irq_line = esp_intr_alloc(cfg->irq_source,
 			0,
 			(ISR_HANDLER)spi_esp32_isr,
@@ -285,19 +302,6 @@ static int IRAM_ATTR spi_esp32_configure(const struct device *dev,
 		return 0;
 	}
 
-	if (!device_is_ready(cfg->clock_dev)) {
-		LOG_ERR("clock control device not ready");
-		return -ENODEV;
-	}
-
-	/* enables SPI peripheral */
-	if (clock_control_on(cfg->clock_dev, cfg->clock_subsys)) {
-		LOG_ERR("Could not enable SPI clock");
-		return -EIO;
-	}
-
-	spi_ll_master_init(hal->hw);
-
 	ctx->config = spi_cfg;
 
 	if (spi_cfg->operation & SPI_HALF_DUPLEX) {

[jurenat]

@LucasTambor I am not sure if I am following you but I agree that the clock initialization should be in the spi_esp32_init. The -EALREADY is still not handled with your change so I added a log to clock_control_esp32_on.

rst:0x1 (POWERON_RESET),boot:0x12 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3ffb0000,len:8416
load:0x40080000,len:41120
entry 0x400850ac
I (34) boot: ESP Simple boot
I (34) boot: compile time Jun  4 2024 10:48:39
W (34) boot: Unicore bootloader
I (34) spi_flash: detected chip: generic
I (37) spi_flash: flash io: dio
I (40) boot: chip revision: v3.0
I (43) boot.esp32: SPI Speed      : 40MHz
I (47) boot.esp32: SPI Mode       : DIO
I (50) boot.esp32: SPI Flash Size : 16MB
I (54) boot: Enabling RNG early entropy source...
[esp32] [INF] DRAM: lma 0x00001020 vma 0x3ffb0000 len 0x20e0   (8416)
[esp32] [INF] IRAM: lma 0x00003108 vma 0x40080000 len 0xa0a0   (41120)
[esp32] [INF] padd: lma 0x0000d1b8 vma 0x00000000 len 0x2e40   (11840)
[esp32] [INF] IMAP: lma 0x00010000 vma 0x400d0000 len 0x19208  (102920)
[esp32] [INF] padd: lma 0x00029210 vma 0x00000000 len 0x6de8   (28136)
[esp32] [INF] DMAP: lma 0x00030000 vma 0x3f400000 len 0x216b8  (136888)
[esp32] [INF] Image with 6 segments
[esp32] [INF] DROM segment: paddr=00030000h, vaddr=3f400000h, size=216B8h (136888) map
[esp32] [INF] IROM segment: paddr=00010000h, vaddr=400d0000h, size=19208h (102920) map

[00:00:00.147,000] <dbg> clock_control: esp32_select_rtc_slow_clk: RTC_SLOW_CLK calibration value: 3387241
[00:00:00.148,000] <dbg> clock_control: clock_control_esp32_on: Clock rtc@3ff48000 status 1
[00:00:00.148,000] <dbg> clock_control: clock_control_esp32_on: Clock rtc@3ff48000 status 2
[00:00:00.148,000] <err> esp32_spi: Could not enable SPI clock
[00:00:00.148,000] <dbg> uc81xx: uc81xx_init: 
[00:00:00.148,000] <err> uc81xx: SPI bus spi@3ff65000 not ready
*** Booting Zephyr OS build v3.6.0-5239-ge3866a969071 ***
[00:00:00.149,000] <err> lvgl: Display device not ready.
[00:00:00.149,000] <err> app: Device not ready, aborting test

[LucasTambor]

@LucasTambor I am not sure if I am following you but I agree that the clock initialization should be in the spi_esp32_init. The -EALREADY is still not handled with your change so I added a log to clock_control_esp32_on.

@darkmoon32 Did you apply the changes I suggested? I think we shouldn't handle the -EALREADY, it must return an error if we try to enable the clock twice.

Is this log from any sample or test that I can reproduce?

Just so you know, I tested my suggestion with spi_loopback test and it works fine.

Would you mind applying the diff I sent, without any modification and give me a feedback? Just save it in a file, such as bugfix.patch then apply it with git apply bugfix.patch.

Thanks man. If it fixes your issue feel free to update the PR with it. Otherwise we can dig further.

[jurenat]

@LucasTambor The provided log was recorded with your suggested changes.

I have pushed a minimal project with the issue here. You can check if there is any other issue which could cause the clock issue. I have included the board configuration but you can use esp32_devkitc_wroom/esp32/procpu if you add the uc8179_waveshare_epaper_gdew075t7 node from my board's dts.

Build cmd: west build -p -b espink/esp32/procpu zephyr/samples/drivers/spi_clock_bug/.

Log from the provided sample if I use espink/esp32/procpu in my board:

rst:0x1 (POWERON_RESET),boot:0x12 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3ffb0000,len:8232
load:0x40080000,len:39712
entry 0x40084b7c
I (33) boot: ESP Simple boot
I (33) boot: compile time Jun  5 2024 10:10:02
W (34) boot: Unicore bootloader
I (34) spi_flash: detected chip: generic
I (36) spi_flash: flash io: dio
I (39) boot: chip revision: v3.0
I (42) boot.esp32: SPI Speed      : 40MHz
I (46) boot.esp32: SPI Mode       : DIO
I (50) boot.esp32: SPI Flash Size : 16MB
I (53) boot: Enabling RNG early entropy source...
[esp32] [INF] DRAM: lma 0x00001020 vma 0x3ffb0000 len 0x2028   (8232)
[esp32] [INF] IRAM: lma 0x00003050 vma 0x40080000 len 0x9b20   (39712)
[esp32] [INF] padd: lma 0x0000cb88 vma 0x00000000 len 0x3470   (13424)
[esp32] [INF] IMAP: lma 0x00010000 vma 0x400d0000 len 0x48b4   (18612)
[esp32] [INF] padd: lma 0x000148bc vma 0x00000000 len 0xb73c   (46908)
[esp32] [INF] DMAP: lma 0x00020000 vma 0x3f400000 len 0x1410   (5136)
[esp32] [INF] Image with 6 segments
[esp32] [INF] DROM segment: paddr=00020000h, vaddr=3f400000h, size=01410h (  5136) map
[esp32] [INF] IROM segment: paddr=00010000h, vaddr=400d0000h, size=048B4h ( 18612) map

[00:00:00.146,000] <dbg> clock_control: esp32_select_rtc_slow_clk: RTC_SLOW_CLK calibration value: 3407405
[00:00:00.147,000] <dbg> clock_control: clock_control_esp32_on: Clock rtc@3ff48000 status 1
[00:00:00.147,000] <dbg> clock_control: clock_control_esp32_on: Clock rtc@3ff48000 status 2
[00:00:00.147,000] <err> esp32_spi: Could not enable SPI clock
*** Booting Zephyr OS build v3.6.0-5393-g207a0cb544fd ***
spi@3ff65000: device not ready.

Build cmd for esp32_devkitc_wroom with extra uc8179_waveshare_epaper_gdew075t7 node: west build -p -b esp32_devkitc_wroom/esp32/procpu zephyr/samples/drivers/spi_clock_bug/.

Log from the provided sample if I use esp32_devkitc_wroom/esp32/procpu with extra uc8179_waveshare_epaper_gdew075t7 node in my board:

rst:0x1 (POWERON_RESET),boot:0x12 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3ffb0000,len:8584
load:0x40080000,len:39712
entry 0x40084b7c
I (34) boot: ESP Simple boot
I (34) boot: compile time Jun  5 2024 10:05:10
W (34) boot: Unicore bootloader
I (34) spi_flash: detected chip: generic
I (37) spi_flash: flash io: dio
I (39) boot: chip revision: v3.0
I (42) boot.esp32: SPI Speed      : 40MHz
I (46) boot.esp32: SPI Mode       : DIO
I (50) boot.esp32: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
[esp32] [INF] DRAM: lma 0x00001020 vma 0x3ffb0000 len 0x2188   (8584)
[esp32] [INF] IRAM: lma 0x000031b0 vma 0x40080000 len 0x9b20   (39712)
[esp32] [INF] padd: lma 0x0000cce8 vma 0x00000000 len 0x3310   (13072)
[esp32] [INF] IMAP: lma 0x00010000 vma 0x400d0000 len 0x48b4   (18612)
[esp32] [INF] padd: lma 0x000148bc vma 0x00000000 len 0xb73c   (46908)
[esp32] [INF] DMAP: lma 0x00020000 vma 0x3f400000 len 0x14ac   (5292)
[esp32] [INF] Image with 6 segments
[esp32] [INF] DROM segment: paddr=00020000h, vaddr=3f400000h, size=014ACh (  5292) map
[esp32] [INF] IROM segment: paddr=00010000h, vaddr=400d0000h, size=048B4h ( 18612) map

[00:00:00.146,000] <dbg> clock_control: esp32_select_rtc_slow_clk: RTC_SLOW_CLK calibration value: 3405452
[00:00:00.147,000] <dbg> clock_control: clock_control_esp32_on: Clock rtc@3ff48000 status 1
[00:00:00.147,000] <dbg> clock_control: clock_control_esp32_on: Clock rtc@3ff48000 status 2
[00:00:00.147,000] <err> esp32_spi: Could not enable SPI clock
[00:00:00.147,000] <dbg> clock_control: clock_control_esp32_on: Clock rtc@3ff48000 status 2
[00:00:00.147,000] <err> esp32_spi: Could not enable SPI clock
*** Booting Zephyr OS build v3.6.0-5393-g207a0cb544fd ***
spi@3ff65000: device not ready.

I hope it will reproduce the issue for you.

[LucasTambor]

@darkmoon32 Thanks! Now it is clear to me that the problem still occur with ESP32.

The problem is that we wasn't disabling SPI2 and SPI3 clocks for ESP32, and that should only happen when CONFIG_SPIRAM_SPEED_80M is enabled.

Can you try #73807 and see if it fix your issue? Thanks

[jurenat]

@darkmoon32 Thanks! Now it is clear to me that the problem still occur with ESP32.

The problem is that we wasn't disabling SPI2 and SPI3 clocks for ESP32, and that should only happen when CONFIG_SPIRAM_SPEED_80M is enabled.

Can you try #73807 and see if it fix your issue? Thanks

The #73807 worked for me. This PR is therefore outdated so I am closing it. Thanks for your work.