MTL - Soundwire - clock stop prep/de-prep failed slave:15 #4619
Comments
|
-110 is ETIMEDOUT I have no idea what setup you are using @udaymb, please add this file Also adding @rfvirgil and @charleskeepax for comments, IIRC there's something specific about clock stop with this CS42L42 device? |
|
On 06/10/2023 14:27, Pierre-Louis Bossart wrote:
-110 is ETIMEDOUT
slave:15 is a broadcast command to all peripherals.
I have no idea what setup you are using @udaymb, please add this file
[sof-dyndbg.conf.txt](https://github.com/thesofproject/linux/files/12831545/sof-dyndbg.conf.txt) as /etc/modprobe.d/sof-dyndbg.conf and re-attach the logs.
Also adding @rfvirgil and @charleskeepax for comments, IIRC there's something specific about clock stop with this CS42L42 device?
The CS42L42 clock-stop issue is that jack detect can't send a bus wake
so it needs a separate INT line to notify jack plug/unplug events to
the host. This doesn't prevent entering or leaving clock-stop.
Do we know whether the -110 means there was no _response_ from the
CS42L42, or that it responded with clock-stop not allowed?
|
|
@rfvirgil my guess based on the limited logs is that the broadcast read fails static int sdw_bus_wait_for_clk_prep_deprep(struct sdw_bus *bus, u16 dev_num)
{
int retry = bus->clk_stop_timeout;
int val;
do {
val = sdw_bread_no_pm(bus, dev_num, SDW_SCP_STAT);
if (val < 0) {
if (val != -ENODATA)
dev_err(bus->dev, "SDW_SCP_STAT bread failed:%d\n", val);
return val;
}
val &= SDW_SCP_STAT_CLK_STP_NF;
if (!val) {
dev_dbg(bus->dev, "clock stop prep/de-prep done slave:%d\n",
dev_num);
return 0;
}
usleep_range(1000, 1500);
retry--;
} while (retry);
dev_err(bus->dev, "clock stop prep/de-prep failed slave:%d\n",
dev_num);
return -ETIMEDOUT;
}We certainly need more logs but my money is on the "NotFinished" bit remaining set. If there was really a command issue we would not see the last dev_err() log. |
|
On 06/10/2023 15:07, Pierre-Louis Bossart wrote:
@rfvirgil my guess based on the limited logs is that the broadcast read fails
````c
static int sdw_bus_wait_for_clk_prep_deprep(struct sdw_bus *bus, u16 dev_num)
{
int retry = bus->clk_stop_timeout;
int val;
do {
val = sdw_bread_no_pm(bus, dev_num, SDW_SCP_STAT);
if (val < 0) {
if (val != -ENODATA)
dev_err(bus->dev, "SDW_SCP_STAT bread failed:%d\n", val);
return val;
}
val &= SDW_SCP_STAT_CLK_STP_NF;
if (!val) {
dev_dbg(bus->dev, "clock stop prep/de-prep done slave:%d\n",
dev_num);
return 0;
}
usleep_range(1000, 1500);
retry--;
} while (retry);
dev_err(bus->dev, "clock stop prep/de-prep failed slave:%d\n",
dev_num);
return -ETIMEDOUT;
}
````
We certainly need more logs but my money is on the "NotFinished" bit remaining set. If there was really a command issue we would not see the last dev_err() log.
A log with DEBUG enabled in cs42l42.c and cs42l42-sdw.c would give us
some extra info. There is a dev_dbg when it handles the port_prep()
callback, and also when it enters and leaves runtime-suspend.
|
|
That's not the port prep that's the issue here, it's the clock stop prep/deprep. Similar logic and wording but different steps. Ports are prepared/deprepared due to streaming actions, clock stop prep/deprep happens in suspend-resume steps. |
|
On 06/10/2023 15:21, Pierre-Louis Bossart wrote:
That's not the port prep that's the issue here, it's the clock stop prep/deprep. Similar logic and wording but different steps. Ports are prepared/deprepared due to streaming actions, clock stop prep/deprep happens in suspend-resume steps.
Sorry, I was getting confused between the two similar but different
CS42L42 threads. A log with DEBUG in the cs42l42 drivers would still
be useful.
|
@plbossart - As suggested updated sof-dyndbg.conf.txt as /etc/modprobe.d/sof-dyndbg.conf and updated below soundwire codec related in the same file |
|
@plbossart Does MTL issue bus-reset after clock stop? But that isn't in the log where it is exiting clock stop (starting at 216.804360). If unattach_request is correctly 0, the CS42L42 has not been reset, so it will still be in clock stop. Looks like something has gone wrong with sending Clock_Stop_Prepare=0. But there aren't any "trf on Slave %d failed" messages so all the writes were acked. |
|
I don't understand the sequence, there's just not enough information in the broken section |
|
@udaymb please try with this patch and re-attach the logs 0001-soundwire-bus-add-more-meaningful-logs-and-traces.patch.txt |
|
attached logs with patch 0001-soundwire-bus-add-more-meaningful-logs-and-traces.patch.txt |
|
Thanks @udaymb, that's what I suspected: Somehow the CS42L42 does not clear the NotFinished bit. This doesn't seem correct, but it doesn't really matter in the end, the error is squelched into a dev_warn and the resume proceeds anyways. I don't really know what to make of this. This happens only on the exit from clock-stop, but the NotFinished logic is the same for the entry in clock-stop. The same logic has been used on all SoundWire devices. @rfvirgil any ideas? |
The same logic is used for clock stop prepare and deprepare, and having different logs for the two steps helps identify problems. In addition, when the "NotFinished" bit remains set, the error handling is not quite right: a) for the clock stop prepare, the error is handled at the caller level, and the error is ignored: there's no good reason to prevent the pm_runtime suspend from happening. Throwing an error that is later ignored is confusing. b) for the clock stop deprepare, the error is ignored in bus.c and a dev_warn() log shown. Throwing an error is also alarming users for no good reason. For both cases, demoting the error to dev_dbg() makes more sense. Link: thesofproject#4619 Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
|
@plbossart Do you have MTL + cs42l42 SoundWire in your Github automated test system? |
No we do not. We only have basic RVPs with RT711-SDCA. We had a plan to introduce additional boards but it's also from Realtek. |
The same logic is used for clock stop prepare and deprepare, and having different logs for the two steps helps identify problems. In addition, when the "NotFinished" bit remains set, the error handling is not quite right: a) for the clock stop prepare, the error is handled at the caller level, and the error is ignored: there's no good reason to prevent the pm_runtime suspend from happening. Throwing an error that is later ignored is confusing. b) for the clock stop deprepare, the error is ignored in bus.c and a dev_warn() log shown. Throwing an error is also alarming users for no good reason. For both cases, demoting the error to dev_dbg() makes more sense. Link: #4619 Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com>
The same logic is used for clock stop prepare and deprepare, and having different logs for the two steps helps identify problems. In addition, when the "NotFinished" bit remains set, the error handling is not quite right: a) for the clock stop prepare, the error is handled at the caller level, and the error is ignored: there's no good reason to prevent the pm_runtime suspend from happening. Throwing an error that is later ignored is confusing. b) for the clock stop deprepare, the error is ignored in bus.c and a dev_warn() log shown. Throwing an error is also alarming users for no good reason. For both cases, demoting the error to dev_dbg() makes more sense. Link: #4619 Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com> Reviewed-by: Rander Wang <rander.wang@intel.com> Reviewed-by: Richard Fitzgerald <rf@opensource.cirrus.com> Reviewed-by: Bard Liao <yung-chuan.liao@linux.intel.com>
The same logic is used for clock stop prepare and deprepare, and having different logs for the two steps helps identify problems. In addition, when the "NotFinished" bit remains set, the error handling is not quite right: a) for the clock stop prepare, the error is handled at the caller level, and the error is ignored: there's no good reason to prevent the pm_runtime suspend from happening. Throwing an error that is later ignored is confusing. b) for the clock stop deprepare, the error is ignored in bus.c and a dev_warn() log shown. Throwing an error is also alarming users for no good reason. For both cases, demoting the error to dev_dbg() makes more sense. Link: thesofproject#4619 Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com> Reviewed-by: Rander Wang <rander.wang@intel.com> Reviewed-by: Richard Fitzgerald <rf@opensource.cirrus.com> Signed-off-by: Bard Liao <yung-chuan.liao@linux.intel.com> Link: https://lore.kernel.org/r/20231013010812.114216-1-yung-chuan.liao@linux.intel.com Signed-off-by: Vinod Koul <vkoul@kernel.org>
|
@udaymb can we close this issue? no input or follow-up since October. |
|
no reply, closing |
…re/deprepare The same logic is used for clock stop prepare and deprepare, and having different logs for the two steps helps identify problems. In addition, when the "NotFinished" bit remains set, the error handling is not quite right: a) for the clock stop prepare, the error is handled at the caller level, and the error is ignored: there's no good reason to prevent the pm_runtime suspend from happening. Throwing an error that is later ignored is confusing. b) for the clock stop deprepare, the error is ignored in bus.c and a dev_warn() log shown. Throwing an error is also alarming users for no good reason. For both cases, demoting the error to dev_dbg() makes more sense. Link: thesofproject/linux#4619 Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com> Reviewed-by: Rander Wang <rander.wang@intel.com> Reviewed-by: Richard Fitzgerald <rf@opensource.cirrus.com> Signed-off-by: Bard Liao <yung-chuan.liao@linux.intel.com> Link: https://lore.kernel.org/r/20231013010812.114216-1-yung-chuan.liao@linux.intel.com Signed-off-by: Vinod Koul <vkoul@kernel.org> (cherry picked from commit ff435da4cc8b6137be9f0b6b4a9af095590d4b8c https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master) BUG=b:326869955 TEST=Test Audio use cases. Change-Id: Id2ef4f23517ad869e4dc7ffa0a645fe060f8f018 Signed-off-by: Debi sahoo <debix.prasad.sahoo@intel.com>
…re/deprepare The same logic is used for clock stop prepare and deprepare, and having different logs for the two steps helps identify problems. In addition, when the "NotFinished" bit remains set, the error handling is not quite right: a) for the clock stop prepare, the error is handled at the caller level, and the error is ignored: there's no good reason to prevent the pm_runtime suspend from happening. Throwing an error that is later ignored is confusing. b) for the clock stop deprepare, the error is ignored in bus.c and a dev_warn() log shown. Throwing an error is also alarming users for no good reason. For both cases, demoting the error to dev_dbg() makes more sense. Link: thesofproject/linux#4619 Signed-off-by: Pierre-Louis Bossart <pierre-louis.bossart@linux.intel.com> Reviewed-by: Rander Wang <rander.wang@intel.com> Reviewed-by: Richard Fitzgerald <rf@opensource.cirrus.com> Signed-off-by: Bard Liao <yung-chuan.liao@linux.intel.com> Link: https://lore.kernel.org/r/20231013010812.114216-1-yung-chuan.liao@linux.intel.com Signed-off-by: Vinod Koul <vkoul@kernel.org> (cherry picked from commit ff435da https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master) BUG=b:326869955 TEST=Test Audio use cases. Change-Id: Id2ef4f23517ad869e4dc7ffa0a645fe060f8f018 Signed-off-by: Debi sahoo <debix.prasad.sahoo@intel.com> Signed-off-by: Hubert Mazur <hmazur@google.com>
Below issue is observed
Codec - cs42l42 headset and max98363 speaker
In the Chrome MTL system - headset is connected, In UI, during youtube playback is on speaker, if switched to headset, below log is seen in dmesg
soundwire sdw-master-0: clock stop prep/de-prep failed slave:15
soundwire sdw-master-0: clock stop deprepare wait failed:-110
Above message has no effect on audio. Audio is working fine and heard on headset.
Logs - dmesg-clock-prep-deprep-15-110.log
The text was updated successfully, but these errors were encountered: