Skip to content

ASoC/soundwire: Intel: add sdw_intel_pre_exit helper - #4838

Closed
bardliao wants to merge 3 commits into
thesofproject:topic/sof-devfrom
bardliao:for-issue-4809
Closed

bardliao wants to merge 3 commits into
thesofproject:topic/sof-devfrom
bardliao:for-issue-4809

Conversation

@bardliao

@bardliao bardliao commented Feb 23, 2024 •

Copy link
Copy Markdown
Collaborator

We will disable SDW interrupt in hda_sdw_exit() before sdw_intel_exit() and peripherals will on longer access SDW registers. However, when the manager became pm_runtime active in the remove procedure, peripherals will be attach, and do the initialization process. The commit suggests a sdw_intel_pre_exit() function to do the necessary tasks to wait for the peripherals being initialized and avoid futher access SDW registers.

Fixes #4809

Comment thread drivers/soundwire/intel_init.c Outdated
* peripherals will no longer access SDW registers. Disable peripherals
* pm runtime to avoid prevent peripherals from accessing SDW registers.
*/
pm_runtime_disable(&slave->dev);

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sorry @bardliao I am having hard time reconciling this PR with existing comments and code:

Intel aux device says pm_runtime is already disabled?

* Since pm_runtime is already disabled, we don't decrease

and the master code is also with pm_runtime disabled.

pm_runtime_disable(&bus->md->dev);

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@plbossart The PR is trying to disable peripherals pm runtime, not the managers. pm_request_resume(&slave->dev); is called right after a peripheral is initialized, and this PR is trying to avoid it since the runtime resume function will do regcache_sync().
Here are some logs for reference.

  1. dmesg.txt: add trace 0001-Add-trace.patch, without this PR
  2. dmesg_w4838.txt add trace and with thie PR
  3. dmesg_disable_m_pm.txt replace pm_runtime_disable(&slave->dev); by pm_runtime_disable(&bus->md->dev); in sdw_intel_pre_exit()
diff --git a/drivers/soundwire/intel_init.c b/drivers/soundwire/intel_init.c
index 3baa06297c34..528ac11a4dc3 100644
--- a/drivers/soundwire/intel_init.c
+++ b/drivers/soundwire/intel_init.c
@@ -373,6 +373,8 @@ void sdw_intel_pre_exit(struct sdw_intel_ctx *ctx)
                struct sdw_slave *slave;
                unsigned long time;

+               dev_info(&bus->md->dev, "bard: %s calling pm_runtime_disable\n", __func__);
+               pm_runtime_disable(&bus->md->dev);
                list_for_each_entry(slave, &bus->slaves, node) {
                        /*
                         * We usually do regcache_sync in peripherals runtime resume function.
@@ -380,7 +382,8 @@ void sdw_intel_pre_exit(struct sdw_intel_ctx *ctx)
                         * peripherals will no longer access SDW registers. Disable peripherals
                         * pm runtime to avoid prevent peripherals from accessing SDW registers.
                         */
-                       pm_runtime_disable(&slave->dev);
+//                     dev_info(&slave->dev, "bard: %s calling pm_runtime_disable\n", __func__);
+//                     pm_runtime_disable(&slave->dev);
                        /*
                         * We need to wait for peripherals to be initialized before disabling
                         * SDW interrupt

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Changes V2:
Instead of disabling runtime pm, using pm_runtime_resume(&slave->dev); to wait for peripherals being initialized and regmap synced.

Comment thread drivers/soundwire/intel_init.c Outdated
* Make sure peripherals are fully resumed and don't need to access
* SDW registers any more.
*/
pm_runtime_resume(&slave->dev);

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this sounds fine but we need to explain why errors are ignored, and I wonder if for consistency with the prepare step we should use the macro device_for_each_child()

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this sounds fine but we need to explain why errors are ignored, and I wonder if for consistency with the prepare step we should use the macro device_for_each_child()

@plbossart Can we change pm_request_resume(dev); to pm_runtime_resume(dev); and reuse intel_resume_child_device()?

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think so @bardliao. I don't see any reason why the .prepare should rely on an async behavior before stopping the clock, that's also risky with a codec driver potentially doing stuff after the clock is stopped.

That would need to be two patches though, so that we can bisect the changes from pm_request_resume() to pm_runtime_resume() separately from the pre-exit stuff for the remove operation.

We need to wait for each child to fully resume. Use pm_resume_resume
to ensure it.

Signed-off-by: Bard Liao <yung-chuan.liao@linux.intel.com>
We will resume each child in the next patch, and
intel_resume_child_device() will be used.

Signed-off-by: Bard Liao <yung-chuan.liao@linux.intel.com>
@marc-hb

marc-hb commented Mar 2, 2024 •

Copy link
Copy Markdown
Collaborator

@bardliao

bardliao commented Mar 4, 2024

Copy link
Copy Markdown
Collaborator Author

The soundwire failures in https://sof-ci.01.org/linuxpr/PR4838/build1577/devicetest/index.html and https://sof-ci.01.org/linuxpr/PR4838/build1578/devicetest/index.html seem related and relevant.

Thanks @marc-hb I will take a look.

@bardliao

bardliao commented Mar 4, 2024

Copy link
Copy Markdown
Collaborator Author

The soundwire failures in https://sof-ci.01.org/linuxpr/PR4838/build1577/devicetest/index.html and https://sof-ci.01.org/linuxpr/PR4838/build1578/devicetest/index.html seem related and relevant.

@plbossart The issue is that an ALERT is raised when rt1308 is attached. And SDW interrupt is disabled before sdw_handle_slave_alerts() return.

[ 2257.973185] kernel: soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.1: Slave status change: 0x440
[ 2258.485855] kernel: soundwire_intel soundwire_intel.link.1: IO transfer timed out, cmd 2 device 1 addr 42 len 2
[ 2258.485885] kernel: soundwire sdw-master-0-1: trf on Slave 1 failed:-110 read addr 42 count 0
[ 2258.485894] kernel: rt1308 sdw:0:1:025d:1308:00:2: SDW_SCP_INT2/3 recheck read failed:-110
[ 2258.485901] kernel: rt1308 sdw:0:1:025d:1308:00:2: Slave 1 alert handling failed: -110
[ 2258.989832] kernel: soundwire_intel soundwire_intel.link.1: IO transfer timed out, cmd 2 device 2 addr 40 len 1
[ 2258.989858] kernel: soundwire sdw-master-0-1: trf on Slave 2 failed:-110 read addr 40 count 0
[ 2258.989867] kernel: rt1308 sdw:0:1:025d:1308:00:0: SDW_SCP_INT1 read failed:-110
[ 2258.989874] kernel: rt1308 sdw:0:1:025d:1308:00:0: Slave 2 alert handling failed: -110

The pain point is that we don't know when will all ALERT be handled. We didn't see the issue before because we didn't resume each child, and the peripherals won't be attached. Maybe disable pm runtime to avoid peripherals being attached is better? #4843

plbossart
plbossart previously approved these changes Mar 4, 2024

@plbossart plbossart left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sounds good @bardliao, see below a couple of suggested edits for the commit messages

Comment thread drivers/soundwire/intel_init.c Resolved
ret = pm_runtime_resume(dev);
if (ret < 0) {
dev_err(dev, "%s: pm_request_resume failed: %d\n", __func__, ret);
dev_err(dev, "%s: pm_runtime_resume failed: %d\n", __func__, ret);

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

repetition in commit message, it's pm_runtime_resume()

@plbossart

Copy link
Copy Markdown
Member

@plbossart The issue is that an ALERT is raised when rt1308 is attached. And SDW interrupt is disabled before sdw_handle_slave_alerts() return.

Looks like a completely different race condition to me.

First can we clarify why we get an alert for an amplifier?

@plbossart

Copy link
Copy Markdown
Member

@plbossart The issue is that an ALERT is raised when rt1308 is attached. And SDW interrupt is disabled before sdw_handle_slave_alerts() return.

Looks like a completely different race condition to me.

First can we clarify why we get an alert for an amplifier?

We do have a 'disable_irq_lock' mutex for all jack codecs, but we don't have one for the amplifiers.

So that goes back to my question: why do we have alerts now for amps. What changed?

@bardliao

bardliao commented Mar 5, 2024

Copy link
Copy Markdown
Collaborator Author

So that goes back to my question: why do we have alerts now for amps. What changed?

@plbossart It doesn't have to be a real alert, it could be just a parity error. It usually happens when a peripheral is attached.

If I add below log, I can see below log when I just start a playback.

[   97.825801] rt1308 sdw:0:1:025d:1308:00:2: bard: sdw_handle_slave_status got SDW_SLAVE_ALERT
[   97.835357] rt1308 sdw:0:1:025d:1308:00:2: bard: sdw_handle_slave_alerts buf 0x1
[   97.835743] rt1308 sdw:0:1:025d:1308:00:0: bard: sdw_handle_slave_status got SDW_SLAVE_ALERT
[   97.835985] rt1308 sdw:0:1:025d:1308:00:0: bard: sdw_handle_slave_alerts buf 0x1
diff --git a/drivers/soundwire/bus.c b/drivers/soundwire/bus.c
index 191e6cc6f962..a31547df25f4 100644
--- a/drivers/soundwire/bus.c
+++ b/drivers/soundwire/bus.c
@@ -1654,6 +1654,7 @@ static int sdw_handle_slave_alerts(struct sdw_slave *slave)
        }

        do {
+               dev_info(&slave->dev, "bard: %s buf %#x\n", __func__, buf);
                slave_notify = false;

                /*
@@ -1924,6 +1925,8 @@ int sdw_handle_slave_status(struct sdw_bus *bus,
                        break;

                case SDW_SLAVE_ALERT:
+                       dev_info(&slave->dev, "bard: %s got SDW_SLAVE_ALERT\n",
+                               __func__);
                        ret = sdw_handle_slave_alerts(slave);
                        if (ret < 0)
                                dev_err(&slave->dev,

dmesg_tgl_alert.txt

We didn't notice it because we didn't add a trace in the SDW_SLAVE_ALERT case. However, sdw_handle_slave_alerts() will keep reading/writing sdw registers to check/handle interrupts which will cause IO transfer timed out after sdw interrupt is disabled in the removal process.

@marc-hb

marc-hb commented Mar 5, 2024

Copy link
Copy Markdown
Collaborator

It doesn't have to be a real alert, it could be just a parity error. It usually happens when a peripheral is attached.

In that case dev_err() shouldn't be used. Is it still? Does your proposition stops sdw_handle_slave_alerts() from returning an error code? I don't know anything about this issue but we need this for the tests to pass.

If something is expected to happen then it should not cause dev_err() to be invoked. Not even dev_warn() unless it's very unusual.

@bardliao

bardliao commented Mar 5, 2024

Copy link
Copy Markdown
Collaborator Author

It doesn't have to be a real alert, it could be just a parity error. It usually happens when a peripheral is attached.

In that case dev_err() shouldn't be used. Is it still? Does your proposition stops sdw_handle_slave_alerts() from returning an error code? I don't know anything about this issue but we need this for the tests to pass.

No, the error is IO transfer timed out which is shown if a sdw transfer is not completed. That is not expected in most cases. But in the module removal case, it is expected since sdw interrupt is disabled and sdw IO transfer needs sdw interrupt.

If something is expected to happen then it should not cause dev_err() to be invoked. Not even dev_warn() unless it's very unusual.

@marc-hb

marc-hb commented Mar 5, 2024

Copy link
Copy Markdown
Collaborator

But in the module removal case, it is expected since sdw interrupt is disabled and sdw IO transfer needs sdw interrupt.

Is it possible to downgrade the dev_err() in that particular case? It's not unusual to have the same message at a different level depending on the state of the system.

We will disable SDW interrupt in hda_sdw_exit() before sdw_intel_exit()
and peripherals will on longer access SDW registers. However, when
the manager became pm_runtime active in the remove procedure, peripherals
will become attached, and do the initialization process. The commit
suggests a sdw_intel_pre_exit() function and use pm_runtime_resume() to
wait for the peripherals being fully resumed. This will ensure there are
no SoundWire registers accessed after the bus is powered-down.

Signed-off-by: Bard Liao <yung-chuan.liao@linux.intel.com>
@plbossart

Copy link
Copy Markdown
Member

I am having a hard-time following the issue @bardliao

On remove, this is what happens

static void intel_link_remove(struct auxiliary_device *auxdev)
{
	struct sdw_cdns *cdns = auxiliary_get_drvdata(auxdev);
	struct sdw_intel *sdw = cdns_to_intel(cdns);
	struct sdw_bus *bus = &cdns->bus;

	/*
	 * Since pm_runtime is already disabled, we don't decrease
	 * the refcount when the clock_stop_quirk is
	 * SDW_INTEL_CLK_STOP_NOT_ALLOWED
	 */
	if (!bus->prop.hw_disabled) {
		sdw_intel_debugfs_exit(sdw);
		sdw_cdns_enable_interrupt(cdns, false);
	}
	sdw_bus_master_delete(bus);
}

but inside sdw_cdns_enable_interrupt, we use a
When we disable the interrupts in intel_stop_bus(), there's a call to cancel_work_sync() to make sure the current interrupt is fully handled and new ones will not be allowed.

	cdns->interrupt_enabled = state;

	/*
	 * Complete any on-going status updates before updating masks,
	 * and cancel queued status updates.
	 *
	 * There could be a race with a new interrupt thrown before
	 * the 3 mask updates below are complete, so in the interrupt
	 * we use the 'interrupt_enabled' status to prevent new work
	 * from being queued.
	 */
	if (!state)
		cancel_work_sync(&cdns->work);

	cdns_writel(cdns, CDNS_MCP_SLAVE_INTMASK0, slave_intmask0);
	cdns_writel(cdns, CDNS_MCP_SLAVE_INTMASK1, slave_intmask1);
	cdns_writel(cdns, CDNS_MCP_INTMASK, mask);

also

	if (int_status & CDNS_MCP_INT_SLAVE_MASK) {
		/* Mask the Slave interrupt and wake thread */
		cdns_updatel(cdns, CDNS_MCP_INTMASK,
			     CDNS_MCP_INT_SLAVE_MASK, 0);

		int_status &= ~CDNS_MCP_INT_SLAVE_MASK;

		/*
		 * Deal with possible race condition between interrupt
		 * handling and disabling interrupts on suspend.
		 *
		 * If the master is in the process of disabling
		 * interrupts, don't schedule a workqueue
		 */
		if (cdns->interrupt_enabled)
			schedule_work(&cdns->work);
	}

So I don't get how we end-up processing an ALERT after disabling it. And if we have the alert before, then we wait until it's completed.

@bardliao

bardliao commented Mar 6, 2024

Copy link
Copy Markdown
Collaborator Author

@plbossart Please see the trace below.

[   29.691033] soundwire_cadence:cdns_update_slave_status_work: soundwire_intel soundwire_intel.link.1: Slave status change: 0x440
[   29.691067] rt1308 sdw:0:1:025d:1308:00:2: bard: sdw_handle_slave_alerts
[   29.698466] rt1308 sdw:0:1:025d:1308:00:2: bard: sdw_handle_slave_alerts count 0 buf 0x1
[   29.698624] sof-audio-pci-intel-tgl 0000:00:1f.3: bard: hda_sdw_exit disable sdw int
[   29.698628] sof-audio-pci-intel-tgl 0000:00:1f.3: bard: hda_common_enable_sdw_irq enable 0
[   29.698664] soundwire_intel soundwire_intel.link.0: bard: intel_link_remove
[   29.698706] soundwire_intel soundwire_intel.link.0: bard: sdw_cdns_enable_interrupt state 0
[   29.698707] soundwire_intel soundwire_intel.link.0: bard: sdw_cdns_enable_interrupt cancel_work_sync(&cdns->work)
[   29.698710] soundwire_intel soundwire_intel.link.0: bard: sdw_cdns_enable_interrupt write CDNS_MCP_INTMASK
[   29.715363] soundwire_intel soundwire_intel.link.1: bard: intel_link_remove
[   29.715405] soundwire_intel soundwire_intel.link.1: bard: sdw_cdns_enable_interrupt state 0
[   29.715406] soundwire_intel soundwire_intel.link.1: bard: sdw_cdns_enable_interrupt cancel_work_sync(&cdns->work)
[   30.202376] soundwire_intel soundwire_intel.link.1: IO transfer timed out, cmd 3 device 1 addr 40 len 1
[   30.202404] soundwire sdw-master-0-1: trf on Slave 1 failed:-110 write addr 40 count 0
[   30.202413] rt1308 sdw:0:1:025d:1308:00:2: SDW_SCP_INT1 write failed:-110
[   30.202420] rt1308 sdw:0:1:025d:1308:00:2: Slave 1 alert handling failed: -110
[   30.202428] rt1308 sdw:0:1:025d:1308:00:0: bard: sdw_handle_slave_alerts
[   30.706365] soundwire_intel soundwire_intel.link.1: IO transfer timed out, cmd 2 device 2 addr 40 len 1
[   30.706392] soundwire sdw-master-0-1: trf on Slave 2 failed:-110 read addr 40 count 0
[   30.706400] rt1308 sdw:0:1:025d:1308:00:0: SDW_SCP_INT1 read failed:-110
[   30.706407] rt1308 sdw:0:1:025d:1308:00:0: Slave 2 alert handling failed: -110
[   30.706429] soundwire_intel soundwire_intel.link.1: bard: cdns_update_slave_status_work end
[   30.706508] soundwire_intel soundwire_intel.link.1: bard: sdw_cdns_enable_interrupt write CDNS_MCP_INTMASK

The alert happens and sdw irq is disabled before intel_link_remove() is called. We won't be able to access sdw register after hda_common_enable_sdw_irq(sdev, false), right?

I have another interesting finding. I won't get the parity alert if I add msleep(1) before cdns_writel(cdns, CDNS_MCP_SLAVE_INTMASK0, slave_intmask0); in sdw_cdns_enable_interrupt()

        if (!state) {
                dev_info(cdns->dev, "bard: %s cancel_work_sync(&cdns->work)\n", __func__);
                cancel_work_sync(&cdns->work);
        }

        msleep(1);
        cdns_writel(cdns, CDNS_MCP_SLAVE_INTMASK0, slave_intmask0);
        cdns_writel(cdns, CDNS_MCP_SLAVE_INTMASK1, slave_intmask1);
        cdns_writel(cdns, CDNS_MCP_INTMASK, mask);

@plbossart

plbossart commented Mar 6, 2024 •

Copy link
Copy Markdown
Member

The alert happens and sdw irq is disabled before intel_link_remove() is called. We won't be able to access sdw register after hda_common_enable_sdw_irq(sdev, false), right?

Yeah I think we're doing something silly here. Basically we have two interrupt levels, at the Cadence IP and then at the controller level. But for some reason we mask off the controller parts BEFORE masking off in the Cadence IP. That makes no sense to me, and I don't see why we couldn't mask off the controller parts later, more as a safety mechanism or for symmetry with startup)_. One level of masking should be enough to prevent new interrupts to come in....

see 2e6c5c5 for an update

@plbossart

Copy link
Copy Markdown
Member

simpler version suggested in #4849 (no need for pre-exit, we can do the interrupt disabling later).

@bardliao

bardliao commented Mar 7, 2024

Copy link
Copy Markdown
Collaborator Author

simpler version suggested in #4849 (no need for pre-exit, we can do the interrupt disabling later).

Aha, that is the first commit of my PR #4833. I tested #4849, it can solve the issue and no regression found.

@plbossart

Copy link
Copy Markdown
Member

replaced by #4849

@plbossart plbossart closed this Mar 11, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

SoundWire: transfer timed out in suspend-resume-without-audio

3 participants