SKL+ ipc timeout fix series by keyonjie · Pull Request #845 · thesofproject/linux

keyonjie · 2019-04-18T04:36:49Z

Several fixes here:

fix trigger stop timeout(low possibility) issue via introducing work for period eplase reporting.
fix ipc->irq_status modified by stream interrupt arriving issue.
refine stream interrupt handler to handle real stream interrupt only.

juimonen · 2019-04-18T06:35:19Z

@Keyon the only issues with work queue solution I have is that:

will it have some effect to userspace as position updates might be delayed?
would there be a way to identify we are in deferred thread processing and only queue work then
(in_interrupt() doesn't work here)?

ranj063 · 2019-04-18T06:46:19Z

@keyonjie a question for my understanding: When you say that executing the pcm_elapsed in the stream irq handler will cause the stop ipc to timeout because the IPC interrupts are disabled. Why is that the case?

juimonen · 2019-04-18T06:46:44Z

@keyonjie I guess the general implicit rule we have here is "it is never allowed to call ipc back to dsp from receive message irq handling (deferred or not)" as it will always lead to timeout. Now how to make sure that will not happen? This PR will block the position update path, but is there some other paths we might have?

juimonen · 2019-04-18T06:48:45Z

@ranj063 it is because in irq thread handling we have ipc busy bit enabled (so irq is disabled) and we are calling message send to dsp and waiting for ack (which will not arrive as we have disabled irq).

juimonen · 2019-04-18T06:51:06Z

@ranj063 so problem is that calling alsa core's period elapsed will call pcm_stop depending on stream state (for e.g. draining or xrun) -> this will lead to sending message to dsp in receive irq handler.

ranj063 · 2019-04-18T06:53:43Z

@ranj063 it is because in irq thread handling we have ipc busy bit enabled (so irq is disabled) and we are calling message send to dsp and waiting for ack (which will not arrive as we have disabled irq).

@juimonen Thanks but I still dont get this. We do this for all IPC's isnt it. set busy bit, send message and wait for reply. Whats different here?

juimonen · 2019-04-18T07:00:26Z

@ranj063 So this problematic call is not coming from userspace or kernel, it is coming from our own receive irq handler. Receive irq handler has enabled busy bit and is calling send message and waiting for ack. so we are sleeping with busy bit on -> it means that "don't send us anything because we are busy". I'm not sure about the internal workings: so is the irq just not coming, is the dsp checking the busy bit and not sending. Anyway we should "release" the ipc before sending, otherwise it will result in timeout.

ranj063 · 2019-04-18T07:03:43Z

@ranj063 So this problematic call is not coming from userspace or kernel, it is coming from our own receive irq handler. Receive irq handler has enabled busy bit and is calling send message and waiting for ack. so we are sleeping with busy bit on -> it means that "don't send us anything because we are busy". I'm not sure about the internal workings: so is the irq just not coming, is the dsp checking the busy bit and not sending. Anyway we should "release" the ipc before sending, otherwise it will result in timeout.

@juimonen sorry but what is the receive irq_handler? could you tell me the name of the handler?

juimonen · 2019-04-18T07:08:14Z

so for e.g. in intel/byt.c: byt_irq_handler & byt_irq_thread. You can see that byt_host_done (which disables busy bit, says "we're done") is called after snd_sof_ipc_msgs_rx.

juimonen · 2019-04-18T07:08:39Z

@ranjani see above

keyonjie · 2019-04-18T09:51:06Z

@keyonjie
I think this patch is no related to WHL now? I believe that it will befit the BYT.
I agree with @kv2019i that maybe this is not a right fix. It seems a workaround to make the call for elapsed() change from async to sync

I believe the patch can benefit byt also, need a minor patch added(let me do it since I am already here).
The change here it is actually how we worked on skl- platforms months back, let's do that surgery(splitting sending ipc and waiting for ack) later.

juimonen · 2019-04-18T10:08:31Z

@Keyon probably most specific description is that it's from async to async :) We have the quite new threaded irq method, so we are already running in kernel thread context. However reading the linux irq manuals, we are doing it pretty much as supposed to. So clear the interrupt in first handler, then do message copying in deferred thread. This is all clean and fine. It also allowed to sleep in this deferred processing as it is kernel thread context.

Problem is that we are clearing the interrupt in linux (so kernel can process) but we are telling dsp with busy bit that you can't send messages. This is also fine, because otherwise we could miss interrupt from dsp (as we are processing previous one).

So as I see it the problem is "waiting for receive ack while inside previous receive processing". So far I see your (and mine) solution as the cleanest thing to solve this fast. work queue makes another async call from deferred processing, so we are able to "release" the receive ipc.

We do elapse in interrupt context at the moment, this will lead to ipc timeout at trigger stop with some possibility, where the pcm elapse will call trigger stop and the stop ipc will timeout as the ipc interrupt is disabled at this context. Here we introduce a work to do pcm period elapse, and the stress test shows that it fixes this kind of ipc timeout issue. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

Change to use work for pcm elapse, this will fix trigger stop ipc timeout issue on skl+ platforms. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

To fix the trigger stop ipc timeout issue on platforms where uses position update IPCs. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

…ssue We are using share irq for ipc and stream ioc interrupts, we should check and make sure the interrupt is for ipc before we should store it to sdev->irq_status, otherwise, the previous stored one may be changed(to 0 usually) when a consequent ioc interrupt arrives. Here add check to fix that. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

Add stream_total into sof_intel_hda_dev to store the total hda stream number that the platform can support, and initialize it at stream_init. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

… interrupts only There is risk that the stream interrupt handler will take ipc interrupt and return IRQ_HANDLED, this may lead to ipc interrupt missed issue, here refine stream interrupt hanler to handle only its interrupts, to fix this kind of issues. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

To make sure the same new message won't be handled >= 2 times. Todo: maybe this is not needed. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

keyonjie · 2019-04-18T10:27:31Z

@Keyon the only issues with work queue solution I have is that:

will it have some effect to userspace as position updates might be delayed?

would there be a way to identify we are in deferred thread processing and only queue work then
(in_interrupt() doesn't work here)?

@juimonen I don't worry that as the position update IPC from FW can take even bigger delay, this work mode was what we did before @lyakh's IPC refinement on SKL- platforms, it was proved working fine. OTOH, adding status check and decide defer it or not based on that looks not decent/general. And, in the future, when our IPC 2.0 we change the usage of doorbells to split sending ipc and waiting acknowledge(FW changes might need together).

kv2019i · 2019-04-18T14:04:31Z

@keyonjie wrote:

@juimonen I don't worry that as the position update IPC from FW can take even bigger delay, this
work mode was what we did before @lyakh's IPC refinement on SKL- platforms, it was proved working

Ok, that's good to know, so maybe ok.

fine. OTOH, adding status check and decide defer it or not based on that looks not decent/general.
And, in the future, when our IPC 2.0 we change the usage of doorbells to split sending ipc and waiting > acknowledge(FW changes might need together).

How about detecting that the IPC send is coming from IRQ thread itself and not waiting
on tx_wait()? I noted you responded to this in ( #840 (comment) ) and I agree doing this for all IPC is a big rework.

But how about we only detect the case where we are in the IRQ thread? in_interrupt() did not work, but we could see other means to detect this "loop back" in IPC TX. I did a quick survey and in these cases, the caller is not doing anything with the response anyways, so waiting for the TX response does not seem to be necessary. If this leads to a big rework as well, then I'd vote for deferring the elapsed calls.

plbossart

This should be split in two series

deal with the stream/ipc interrupt handling
deal with period elapsed issues.

Also this does not really explain why we have issues with PulseAudio since PulseAudio does not use period interrupts... Something is very odd in your descriptions.

plbossart · 2019-04-18T14:29:47Z

 	return ret;
 }

+/*


please update your commit message, it doesn't describe the problem nor why this patch helps.
Some of the English is incorrect, I don't know what 'we do elapse' means, nor what the 'PCM elapse' is.
The explanations are so convoluted it's hard to figure things out.
The additional question is why this belongs in the SOF core?

yes, let me refine the commit, as you know, I always need to improve my English. :)

This belongs to SOF PCM core, not only for DPIB mode, it is similar to sof/ipc.c, SKL- or any other platforms which using SOF IPC mechanism should use it, you can see it is used in the last commit "ASoC: SOF: ipc: change to use snd_sof_pcm_elapsed() for pcm elapse" for byt/bdw...

plbossart · 2019-04-18T14:31:14Z

 	/* new message from DSP */
-	if (hipctdr & CNL_DSP_REG_HIPCTDR_BUSY) {
+	if (hipctdr & CNL_DSP_REG_HIPCTDR_BUSY &&
+	    hipcctl & CNL_DSP_REG_HIPCCTL_BUSY) {


no, we've been there before. The hipcctl register controls the generation of the interrupt, so it's useless to test in the interrupt if the interrupt is enabled. NAK on this one.

let me remove this commit after some experiments here, as written in the commit message, this may be not needed.

plbossart · 2019-04-18T14:32:50Z

+		/* mask BUSY interrupt */
+		snd_sof_dsp_update_bits(sdev, HDA_DSP_BAR,
+					HDA_DSP_REG_HIPCCTL,
+					HDA_DSP_REG_HIPCCTL_BUSY, 0);


where is this unmasked?

plbossart · 2019-04-18T14:40:30Z

@@ -433,15 +433,23 @@ int hda_dsp_stream_hw_params(struct snd_sof_dev *sdev,
 irqreturn_t hda_dsp_stream_interrupt(int irq, void *context)


fix your commit message

ASoC: SOF: Intel: hda-stream: handle real stream interrupts only

The stream and IPC share the same interrupt. The stream interrupt handler mistakenly uses the ipc interrupt
and return IRQ_HANDLED, causing the ipc interrupt to be missed.

Make sure the stream interrupt handler only deals with stream-related interrupts.

Good, thanks, let me take it.

plbossart · 2019-04-18T14:41:08Z

 	u32 status;

+	dev_vdbg(bus->dev, "stream irq, INTSTS status: 0x%x\n",
+		 snd_hdac_chip_readl(bus, INTSTS));


is this necessary? If you add a log, then better add a log of the wrong interrupt being discarded

I hit and debug these issues several rounds, so I want to add a verbose log here for the developer, print out the whole register here is good enough for the developer, it has several bits, the developer need to refer to spec to understand it fully.

plbossart · 2019-04-18T14:44:30Z

 			/* Inform ALSA only in case not do that with IPC */
 			if (sof_hda->no_ipc_position)
-				snd_pcm_period_elapsed(s->substream);
+				snd_sof_pcm_elapsed(s->substream);


I really don't like all this nonsense of no_ipc_position. We are circling on the same problems on how to report the position...

I can imagine, :) but that has no relationship with this PR, right?

plbossart · 2019-04-18T14:45:48Z

 	}

+	/* store the total playback + capture stream number */
+	sof_hda->stream_total = num_total;


why is this needed? You don't use this information for anything in this patch set?

it is used in the consequent stream interrupt refining one, to configure the correct bit mask for interrupt.

somehow your commits are not in the right order in GitHub? It makes the reviews really hard...

plbossart · 2019-04-18T14:46:08Z

@@ -500,6 +500,7 @@ int hda_dsp_stream_init(struct snd_sof_dev *sdev)
 	struct hdac_ext_stream *stream;


fix typos in commit message

sorry don't get this.

add and strore hda stream number

s/strore/store

keyonjie · 2019-04-19T02:14:07Z

@keyonjie wrote:

@juimonen I don't worry that as the position update IPC from FW can take even bigger delay, this
work mode was what we did before @lyakh's IPC refinement on SKL- platforms, it was proved working

Ok, that's good to know, so maybe ok.

fine. OTOH, adding status check and decide defer it or not based on that looks not decent/general.
And, in the future, when our IPC 2.0 we change the usage of doorbells to split sending ipc and waiting > acknowledge(FW changes might need together).

How about detecting that the IPC send is coming from IRQ thread itself and not waiting
on tx_wait()? I noted you responded to this in ( #840 (comment) ) and I agree doing this for all IPC is a big rework.

But how about we only detect the case where we are in the IRQ thread? in_interrupt() did not work, but we could see other means to detect this "loop back" in IPC TX. I did a quick survey and in these cases, the caller is not doing anything with the response anyways, so waiting for the TX response does

@kv2019i I am not quite high on this idea. I believe it is doable in that way, for example, add a new flag like no_wait to sof_ipc_tx_message(), and pass with no_wait=1 for all PCM trigger IPCs(or only for trigger stop).

But what I concern with that is it might lead to kinds of issues with consequent IPCs, e.g. the next IPC TX might fail if it comes fast enough right after this as we are still in holding to the doorbells, it is also a challenge for FW, it is still in handling of trigger stop to the current PCM, but ALSA think it is already stopped, the response to that ALSA sending other IPCs to it(e.g. a new trigger start, or free) might be unpredictable.

not seem to be necessary. If this leads to a big rework as well, then I'd vote for deferring the elapsed calls.

keyonjie · 2019-04-19T02:23:30Z

This should be split in two series

deal with the stream/ipc interrupt handling

deal with period elapsed issues.

Sure, it is easy to do that as they are already split into different commits.
We are still in the verification stage of them in kinds of platforms(you can imagine we might have more than ten kinds of ipc timeout scenario), I put them together here to make it easier to be trace at the moment.

Also this does not really explain why we have issues with PulseAudio since PulseAudio does not use period interrupts... Something is very odd in your descriptions.

wrt Pulseaudio IPC timeout issues, I haven't debugged or checked if this series can fix that, the stream/ipc interrupt handling part might improve it, though the period elapsed part not.

mengdonglin · 2019-04-19T14:24:02Z

@keyonjie @plbossart Today's test on customer CML laptop and WHL (HD-A) RVP showed that thesofproject/sof#1254 cannot be reproduced with this PR, and we can do simultaneous playback of 3 streams and capture of 3 streams, no sound distortion.

plbossart · 2019-04-19T15:38:24Z

@keyonjie @plbossart Today's test on customer CML laptop and WHL (HD-A) RVP showed that thesofproject/sof#1254 cannot be reproduced with this PR, and we can do simultaneous playback of 3 streams and capture of 3 streams, no sound distortion.

it's good news but comments need to be addressed and we need two approvers, so mechanically this PR is delayed until next Tuesday with the long week-end. Please be mindful of time zones, vacations and reviewer availability when you want a PR merged...

keyonjie · 2019-04-19T16:23:09Z

@keyonjie @plbossart Today's test on customer CML laptop and WHL (HD-A) RVP showed that thesofproject/sof#1254 cannot be reproduced with this PR, and we can do simultaneous playback of 3 streams and capture of 3 streams, no sound distortion.

it's good news but comments need to be addressed and we need two approvers, so mechanically this PR is delayed until next Tuesday with the long week-end. Please be mindful of time zones, vacations and reviewer availability when you want a PR merged...

sure, let me do that ASAP. BTW, @plbossart do you prefer splitting this to 2 PRs or 1 PR with split commits is fine?

juimonen

@keyonjie address @plbossart comments and LGTM. My approval is mostly on the work queue issue, and to me (thinking/debugging this for 2 days), this solution seems to be the best/easiest/cleanest thing to do (before bigger ipc refactoring).

plbossart · 2019-04-19T16:54:23Z

@keyonjie @plbossart Today's test on customer CML laptop and WHL (HD-A) RVP showed that thesofproject/sof#1254 cannot be reproduced with this PR, and we can do simultaneous playback of 3 streams and capture of 3 streams, no sound distortion.

it's good news but comments need to be addressed and we need two approvers, so mechanically this PR is delayed until next Tuesday with the long week-end. Please be mindful of time zones, vacations and reviewer availability when you want a PR merged...

sure, let me do that ASAP. BTW, @plbossart do you prefer splitting this to 2 PRs or 1 PR with split commits is fine?

2 PRs please. Also make sure you follow the convention ASoC: SOF: Intel:... for Intel stuff and ASoC: SOF for the rest. ASoC: SOF: hda-ipc is not quite correct.

keyonjie · 2019-04-19T17:36:02Z

OK, then let me close this then.

keyonjie · 2019-04-19T17:55:28Z

the PR is split into #849 and #850, @plbossart @juimonen @kv2019i please help review. Thanks.

keyonjie requested review from juimonen, kv2019i, lgirdwood, lyakh, plbossart, ranj063 and xiulipan and removed request for plbossart April 18, 2019 04:40

juimonen mentioned this pull request Apr 18, 2019

[RFC] ASoC: SOF: ipc: defer position update in non-running state #840

Closed

keyonjie force-pushed the topic/sof-dev branch from f3a1fe4 to 105a416 Compare April 18, 2019 09:36

keyonjie force-pushed the topic/sof-dev branch 2 times, most recently from 11ecfb5 to 0513cdd Compare April 18, 2019 10:23

keyonjie added 5 commits April 18, 2019 18:26

ASoC: SOF: hda-stream: use work for pcm period elapse

7e936ca

Change to use work for pcm elapse, this will fix trigger stop ipc timeout issue on skl+ platforms. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

ASoC: SOF: ipc: change to use snd_sof_pcm_elapsed() for pcm elapse

05aec05

To fix the trigger stop ipc timeout issue on platforms where uses position update IPCs. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

ASoC: SOF: hda-stream: add and strore hda stream number

0dce7e0

Add stream_total into sof_intel_hda_dev to store the total hda stream number that the platform can support, and initialize it at stream_init. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

keyonjie added 2 commits April 18, 2019 18:26

ASoC: SOF: cnl: add check for handling ipc new message from dsp

0513cdd

To make sure the same new message won't be handled >= 2 times. Todo: maybe this is not needed. Signed-off-by: Keyon Jie <yang.jie@linux.intel.com>

plbossart requested changes Apr 18, 2019

View reviewed changes

juimonen approved these changes Apr 19, 2019

View reviewed changes

keyonjie closed this Apr 19, 2019

		@@ -433,15 +433,23 @@ int hda_dsp_stream_hw_params(struct snd_sof_dev *sdev,
		irqreturn_t hda_dsp_stream_interrupt(int irq, void *context)

		@@ -500,6 +500,7 @@ int hda_dsp_stream_init(struct snd_sof_dev *sdev)
		struct hdac_ext_stream *stream;

Conversation

keyonjie commented Apr 18, 2019

Uh oh!

juimonen commented Apr 18, 2019

Uh oh!

ranj063 commented Apr 18, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

juimonen commented Apr 18, 2019

Uh oh!

juimonen commented Apr 18, 2019

Uh oh!

juimonen commented Apr 18, 2019

Uh oh!

ranj063 commented Apr 18, 2019

Uh oh!

juimonen commented Apr 18, 2019

Uh oh!

ranj063 commented Apr 18, 2019

Uh oh!

juimonen commented Apr 18, 2019

Uh oh!

juimonen commented Apr 18, 2019

Uh oh!

keyonjie commented Apr 18, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

juimonen commented Apr 18, 2019

Uh oh!

keyonjie commented Apr 18, 2019

Uh oh!

kv2019i commented Apr 18, 2019

Uh oh!

plbossart left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

keyonjie commented Apr 19, 2019

Uh oh!

keyonjie commented Apr 19, 2019

Uh oh!

mengdonglin commented Apr 19, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

plbossart commented Apr 19, 2019

Uh oh!

ranj063 commented Apr 18, 2019 •

edited

Loading

keyonjie commented Apr 18, 2019 •

edited

Loading

plbossart left a comment •

edited

Loading

mengdonglin commented Apr 19, 2019 •

edited

Loading