SAI2 MCLK not set, codec cannot get MCLK freq

[jasonj2]

Hello everyone, 

I am trying to debug a custom board with STM32MP151 with WM8988 connected with SAI2, the connection is just as  STM32MP15x-DK with except that there is no I2S to HDMI. The device tree configuration is a mimic of STM32MP15xx-dkx.dtsi. After bootup, the soundcard was created, and I can run alsamixer.

The problem is whenever I try to play a sound, the driver complains about cannot get MCLK because the freq passed to wm8988_set_dai_sysclk() is zero. The log messages shown that the asoc try to configure the dai, but it passed the wrong MCLK freq to wm8988 dai. I don't know why? Is there something I am missing in the device tree? 

Also, I tried to enable DEBUG in stm32_sai_sub.c and find that stm32_sai_mclk_enable() may not be called because I cannot find “Enable master clock” in dmesg.

I am using openstlinux eco system 4, the distro version is 4.0.11.

Here is the snipet of the device tree. 

&i2c4{
	pinctrl-names = "default", "sleep";
	pinctrl-0 = <&i2c4_pins_z_mx>;
	pinctrl-1 = <&i2c4_sleep_pins_z_mx>;
	status = "okay";

	/* USER CODE BEGIN i2c4 */
	i2c-scl-rising-time-ns = <185>;
	i2c-scl-falling-time-ns = <20>;
	clock-frequency = <100000>;

	wm8988: wm8988@1b {
		compatible = "wlf,wm8988";
		#sound-dai-cells = <0>;
		reg = <0x1b>;
		status = "okay";

		DBVDD-supply = <&v3v3>;
		DCVDD-supply = <&v3v3>;
		AVDD-supply  = <&vcc_audio>;
		HPVDD-supply = <&vcc_audio>;
	
		clocks = <&sai2a>;
		clock-names = "MCLK";

		ports {
			#address-cells = <1>;
			#size-cells = <0>;

			wm8988_tx_endpoint: port@0 {
				reg = <0>;
				remote-endpoint = <&sai2a_endpoint>;
				frame-master;// = <&wm8988_tx_endpoint>;
				bitclock-master;// = <&wm8988_tx_endpoint>;
			};

			wm8988_rx_endpoint: port@1 {
				reg = <1>;
				remote-endpoint = <&sai2b_endpoint>;
				frame-master;// = <&wm8988_rx_endpoint>;
				bitclock-master;// = <&wm8988_rx_endpoint>;
			};
		};
	};

	/* USER CODE END i2c4 */
};

&sai2{
	pinctrl-names = "default", "sleep";
	pinctrl-0 = <&sai2a_pins_mx>, <&sai2b_pins_mx>;
	pinctrl-1 = <&sai2a_sleep_pins_mx>, <&sai2b_sleep_pins_mx>;
	status = "okay";

	/* USER CODE BEGIN sai2 */
	clocks = <&rcc SAI2>, <&rcc PLL3_Q>, <&rcc PLL3_R>;
	clock-names = "pclk", "x8k", "x11k";
	/* USER CODE END sai2 */

	sai2a: audio-controller@4400b004{
		status = "okay";

		/* USER CODE BEGIN sai2a */
		#clock-cells = <0>;
		dma-names = "tx";

		 sai2a_port: port {
			sai2a_endpoint: endpoint {
				remote-endpoint = <&wm8988_tx_endpoint>;
				format = "i2s";
				mclk-fs = <256>;
				dai-tdm-slot-num = <2>;
				dai-tdm-slot-width = <32>;
			};
		};
		/* USER CODE END sai2a */
	};

	sai2b: audio-controller@4400b024{
		status = "okay";

		/* USER CODE BEGIN sai2b */
		dma-names = "rx";
		st,sync = <&sai2a 2>;
		clocks = <&rcc SAI2_K>, <&sai2a>;
		clock-names = "sai_ck", "MCLK";

		sai2b_port: port {
			sai2b_endpoint: endpoint {
				remote-endpoint = <&wm8988_rx_endpoint>;
				format = "i2s";
				mclk-fs = <256>;
				dai-tdm-slot-num = <2>;
				dai-tdm-slot-width = <32>;
			};
		};
		/* USER CODE END sai2b */
	};
};

/ {	
	sound: sound {
		compatible = "audio-graph-card";
		// label = "BM32MP15-Audio-Card";
		label = "STM32MP15DK";

		widgets = 
			"Headphone",  "Headphone Jack",
			"Microphone", "Microphone Jack",
			"Speaker",    "Speaker External";
		
		routing =
			"Speaker External", "LOUT2",
			"Speaker External", "ROUT2",
			"Headphone Jack", "ROUT1",
			"Headphone Jack", "LOUT1",
			"Playback",  "MCLK",
			"Capture",   "MCLK";

		dais = <&sai2a_port &sai2b_port>;
		status = "okay";
	};
};

Here is the dmesg logs related to sai,  codec, and card. The last six lines were outputed after I try to play a sound by 'speaker-test -t sine‘.

[   35.334229] platform 4400b004.audio-controller: Fixing up cyclic dependency with 1-001b
[   35.397741] spi_stm32 4000b000.spi: driver initialized (master mode)
[   35.453774] platform 4400b024.audio-controller: Fixing up cyclic dependency with 1-001b
[   35.588275] wm8988 1-001b: wm8988_i2c_probe
[   35.591486] wm8988: probe of 1-001b failed with error 517
[   35.651872] wm8988 1-001b: wm8988_i2c_probe
[   35.655040] wm8988: probe of 1-001b failed with error 517
[   37.854538] using random self ethernet address
[   37.905182] using random host ethernet address
[   38.125237] usb0: HOST MAC 04:5e:be:d5:a7:58
[   38.148229] usb0: MAC da:21:72:16:95:ef
[   38.158513] dwc2 49000000.usb-otg: bound driver configfs-gadget
[   38.871318] wm8988 1-001b: wm8988_i2c_probe
[   38.874543] wm8988: probe of 1-001b failed with error 517
[   38.883777] st,stm32-sai-sub 4400b004.audio-controller: Register master clock sai2a_mclk
[   38.919012] st,stm32-sai-sub 4400b024.audio-controller: 4400b024.audio-controller synchronized with audio-controller@4400b004
[   38.919087] st,stm32-sai-sub 4400b024.audio-controller: sai->sai_mclk = -1001602112
[   38.947195] wm8988 1-001b: wm8988_i2c_probe
[   38.983375] wm8988 1-001b: wm8988->mclk_handle = c44cc700
[   39.051048] st,stm32-sai-sub 4400b004.audio-controller: Masks tx/rx:0x3/0x3, slots:2, width:32
[   39.051530] st,stm32-sai-sub 4400b004.audio-controller: fmt 1001
[   39.052755] st,stm32-sai-sub 4400b024.audio-controller: Masks tx/rx:0x3/0x3, slots:2, width:32
[   39.063902] st,stm32-sai-sub 4400b024.audio-controller: fmt 1001
[   39.063952] st,stm32-sai-sub 4400b024.audio-controller: Synchronized SAI configured as slave
[   39.589379] RESIZE-HELPER START
[   40.099033] RESIZE-HELPER: Using systemd-growfs
[   40.156450] EXT4-fs (mmcblk0p10): resizing filesystem from 753664 to 753664 blocks
[   40.222898] EXT4-fs (mmcblk0p8): resizing filesystem from 65536 to 65536 blocks
[   40.282788] EXT4-fs (mmcblk0p9): resizing filesystem from 16384 to 16384 blocks
[   40.342421] EXT4-fs (mmcblk0p11): resizing filesystem from 727516 to 727518 blocks
[   40.358282] EXT4-fs (mmcblk0p11): resized filesystem to 727518
[   40.410548] Filesystem       Size  Used Avail Use% Mounted on
               devtmpfs         178M     0  178M   0% /dev
               /dev/mmcblk0p10  685M  125M  525M  20% /
               tmpfs            245M     0  245M   0% /dev/shm
               tmpfs             98M  8.6M   90M   9% /run
               tmpfs            4.0M     0  4.0M   0% /sys/fs/cgroup
               tmpfs            245M     0  245M   0% /tmp
               /dev/mmcblk0p8    55M   13M   39M  25% /boot
               /dev/mmcblk0p9    14M  6.0M  6.7M  48% /vendor
               /dev/mmcblk0p11  660M  148K  620M   1% /usr/local
               tmpfs            245M     0  245M   0% /var/volatile
[   40.488909] RESIZE-HELPER FINISH
[   40.906720] RESIZE-HELPER START
[   41.013085] RESIZE-HELPER: Using systemd-growfs
[   41.058996] EXT4-fs (mmcblk0p10): resizing filesystem from 753664 to 753664 blocks
[   41.090163] EXT4-fs (mmcblk0p8): resizing filesystem from 65536 to 65536 blocks
[   41.121164] EXT4-fs (mmcblk0p9): resizing filesystem from 16384 to 16384 blocks
[   41.152169] EXT4-fs (mmcblk0p11): resizing filesystem from 727518 to 727518 blocks
[   41.173337] Filesystem       Size  Used Avail Use% Mounted on
               devtmpfs         178M     0  178M   0% /dev
               /dev/mmcblk0p10  685M  125M  525M  20% /
               tmpfs            245M     0  245M   0% /dev/shm
               tmpfs             98M  8.6M   90M   9% /run
               tmpfs            4.0M     0  4.0M   0% /sys/fs/cgroup
               tmpfs            245M     0  245M   0% /tmp
               /dev/mmcblk0p8    55M   13M   39M  25% /boot
               /dev/mmcblk0p9    14M  6.0M  6.7M  48% /vendor
               /dev/mmcblk0p11  660M  148K  620M   1% /usr/local
               tmpfs            245M     0  245M   0% /var/volatile
[   41.234053] RESIZE-HELPER FINISH
[   44.718102] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[   44.768910] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[   45.237727] stm32-dwmac 5800a000.ethernet eth0: PHY [stmmac-0:01] driver [RTL8211F Gigabit Ethernet] (irq=POLL)
[   45.258267] stm32-dwmac 5800a000.ethernet eth0: Register MEM_TYPE_PAGE_POOL RxQ-0
[   45.275609] dwmac4: Master AXI performs any burst length
[   45.287727] stm32-dwmac 5800a000.ethernet eth0: No Safety Features support found
[   45.293887] stm32-dwmac 5800a000.ethernet eth0: IEEE 1588-2008 Advanced Timestamp supported
[   45.334072] stm32-dwmac 5800a000.ethernet eth0: registered PTP clock
[   45.350189] stm32-dwmac 5800a000.ethernet eth0: configuring for phy/rgmii-id link mode
[   48.570866] stm32-dwmac 5800a000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[   48.587664] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[  280.586461] wm8988 1-001b: No MCLK configured, call set_sysclk() on init
[  280.591971] wm8988 1-001b: ASoC: error at snd_soc_dai_startup on wm8988-hifi: -22
[  280.605747] wm8988 1-001b: set sysclk, freq = 0
[  280.612190] wm8988 1-001b: could not set sysclk, freq = 0
[  280.616181] wm8988 1-001b: ASoC: error at snd_soc_dai_set_sysclk on wm8988-hifi: -22
[  280.627751]  4400b004.audio-controller-wm8988-hifi: __soc_pcm_open() failed (-22)

Here is the lsmod output:

Module                  Size  Used by
cfg80211              651264  0
stm32_adc              36864  0
stm32_timer_trigger    20480  1 stm32_adc
stm32_lptimer_trigger    16384  1 stm32_adc
snd_soc_stm32_sai_sub    28672  8
pwm_stm32              20480  0
snd_soc_audio_graph_card    16384  0
snd_soc_simple_card_utils    20480  1 snd_soc_audio_graph_card
stm32_adc_core         20480  0
stm32_timers           16384  1 pwm_stm32
snd_soc_stm32_sai      16384  0
spi_stm32              24576  0
usb_f_ncm              24576  2
u_ether                20480  1 usb_f_ncm
libcomposite           49152  10 usb_f_ncm
sch_fq_codel           20480  3
snd_soc_wm8988         28672  1
snd_soc_core          180224  4 snd_soc_audio_graph_card,snd_soc_wm8988,snd_soc_simple_card_utils,snd_soc_stm32_sai_sub
snd_pcm_dmaengine      16384  1 snd_soc_core
snd_pcm                94208  4 snd_pcm_dmaengine,snd_soc_wm8988,snd_soc_core,snd_soc_stm32_sai_sub
snd_timer              28672  1 snd_pcm
snd                    53248  4 snd_timer,snd_soc_core,snd_pcm,snd_soc_stm32_sai_sub
soundcore              16384  1 snd
fusb302                28672  0
tcpm                   65536  1 fusb302
typec                  36864  1 tcpm
ip_tables              24576  0
x_tables               24576  1 ip_tables
ipv6                  507904  28

Here is the output of clk_summary:

    pll3                              1        1        0   417755859          0     0  50000         Y
       pll3_r                         0        0        0    11290699          0     0  50000         N
       pll3_q                         0        0        0    24573875          0     0  47058         N
          sai2_k                      0        0        0    24573875          0     0  50000         N
             sai2a_mclk               0        0        0           0          0     0  50000         ?

Here is the output of 'ls /dev/snd'

by-path  controlC0  pcmC0D0p  pcmC0D1c  timer

Thanks and any comments would be appreciated.

[Christophe Guibout · Accepted solution]

Hi @jasonj2,

The sound / SAI / Codec DT configuration looks good.

Could you please cross-check the SAI2_MCLK PIN configuration (should be in sai2a_pins_mx) is aligned with your hardware ?

Do you have an idea about why it takes so much time for the codec to be probed ? I noticed a lot of PROBE_DEFER which means that the driver is waiting something.....

Regarding the MCLK error : I would check with a scope if the the MCLK is really there or not : it would help to understand if the problem comes from SAI (clock, pin muxing configuration), or from the codec.

BTW, did you check if function wm8988_set_dai_sysclk() was called during codec driver init ?

BR,

Christophe

[jasonj2]

Hi@Christophe Guibout 

(1) I checked the PIN configuration, I think it is right. Here is the PIN configuration for sai2a/b

    sai2a_pins_mx: sai2a_mx-0 {
        pins {
            pinmux = <STM32_PINMUX('I', 4, AF10)>, /* SAI2_MCLK_A */
                     <STM32_PINMUX('I', 5, AF10)>, /* SAI2_SCK_A */
                     <STM32_PINMUX('I', 6, AF10)>, /* SAI2_SD_A */
                     <STM32_PINMUX('I', 7, AF10)>; /* SAI2_FS_A */
            bias-disable;
            drive-push-pull;
            slew-rate = <0>;
        };
    };

    sai2a_sleep_pins_mx: sai2a_sleep_mx-0 {
        pins {
            pinmux = <STM32_PINMUX('I', 4, ANALOG)>, /* SAI2_MCLK_A */
                     <STM32_PINMUX('I', 5, ANALOG)>, /* SAI2_SCK_A */
                     <STM32_PINMUX('I', 6, ANALOG)>, /* SAI2_SD_A */
                     <STM32_PINMUX('I', 7, ANALOG)>; /* SAI2_FS_A */
        };
    };

    sai2b_pins_mx: sai2b_mx-0 {
        pins {
            pinmux = <STM32_PINMUX('G', 10, AF10)>; /* SAI2_SD_B */
            bias-disable;
            drive-push-pull;
            slew-rate = <0>;
        };
    };

    sai2b_sleep_pins_mx: sai2b_sleep_mx-0 {
        pins {
            pinmux = <STM32_PINMUX('G', 10, ANALOG)>; /* SAI2_SD_B */
        };
    };

(2) Yes, there is some PROBE_DEFER. I checked it, they are produced by wm8988_i2c_probe() because it cannot get MCLK from SAI (), but it looks it can finally get MCLK after tries. I don't know why.

	wm8988->mclk_handle = devm_clk_get(&i2c->dev, "MCLK");
	if (IS_ERR(wm8988->mclk_handle)) {
		dev_err(&i2c->dev, "Failed to get MCLK from %s\n", dev_name(&i2c->dev));
		if (PTR_ERR(wm8988->mclk_handle) != -ENOENT)
			return PTR_ERR(wm8988->mclk_handle);
		wm8988->mclk_handle = NULL;
	}

(3) I confirm wm8988_set_dai_sysclk() was called with freq=0, because there are log looks like "wm8988 1-001b: could not set sysclk, freq = 0" which is a debug output I made in the source code.

Sorry, I clicked the "Accept as Solution" by mistake. The problem still remains.

Best regards,

JasonJ

[Christophe Guibout]

Hello @jasonj2,

I will try to summarize : 

- The SAI configuration looks good

- The Codec configuration looks good

- Several probe_defer because SAI doesn't seem to provide MCLK, but after a while, it seems to be there.

For me, we need to know if the MCLK signal is really there on the wire:

- if yes, we need to focus on the codec

- if no, we need to focus on SAI

- if no, and after a while yes, understand what is the event which enables the clock so late.

BR

Christophe