[alsa-devel] CPU hook snd_hda_intel

[Takashi Iwai]

On Sat, 07 Dec 2019 21:06:43 +0100,
Klaus Ethgen wrote:
> 
> Hi Takashi,
> 
> Am Mi den  4. Dez 2019 um 17:31 schrieb Takashi Iwai:
> > I guess checking the perf output would give you more clue, e.g. which
> > function is hogging the CPU.  Without such information, it's very hard
> > to diagnose...
> 
> No problem, I just had the problem today again.
> 
> Find attached the perf output of the relevant event handler.

Thanks.  So it seems wasting in the busy loop for waiting for the
response from the codec.

How about a patch below?  It's untested, might break things, but at
least avoiding a busy loop.

BTW, if your machine is Coffeelake or Cannonlake, this patch wont'
work on the old branch because of forced polling mode.  It was removed
in 5.5-rc1, so please test with Linus tree at best.


Takashi

--- a/include/sound/hdaudio.h
+++ b/include/sound/hdaudio.h
@@ -317,6 +317,7 @@ struct hdac_bus {
 	struct hdac_rb corb;
 	struct hdac_rb rirb;
 	unsigned int last_cmd[HDA_MAX_CODECS];	/* last sent command */
+	wait_queue_head_t rirb_waitq;
 
 	/* CORB/RIRB and position buffers */
 	struct snd_dma_buffer rb;
diff --git a/sound/hda/hdac_bus.c b/sound/hda/hdac_bus.c
index 8f19876244eb..5eb58fce5353 100644
--- a/sound/hda/hdac_bus.c
+++ b/sound/hda/hdac_bus.c
@@ -43,6 +43,7 @@ int snd_hdac_bus_init(struct hdac_bus *bus, struct device *dev,
 	mutex_init(&bus->cmd_mutex);
 	mutex_init(&bus->lock);
 	INIT_LIST_HEAD(&bus->hlink_list);
+	init_waitqueue_head(&bus->rirb_waitq);
 	bus->irq = -1;
 	return 0;
 }
diff --git a/sound/hda/hdac_controller.c b/sound/hda/hdac_controller.c
index 7e7be8e4dcf9..cd8fa9aa599d 100644
--- a/sound/hda/hdac_controller.c
+++ b/sound/hda/hdac_controller.c
@@ -216,6 +216,9 @@ void snd_hdac_bus_update_rirb(struct hdac_bus *bus)
 		else if (bus->rirb.cmds[addr]) {
 			bus->rirb.res[addr] = res;
 			bus->rirb.cmds[addr]--;
+			if (!bus->rirb.cmds[addr] &&
+			    waitqueue_active(&bus->rirb_waitq))
+				wake_up(&bus->rirb_waitq);
 		} else {
 			dev_err_ratelimited(bus->dev,
 				"spurious response %#x:%#x, last cmd=%#08x\n",
diff --git a/sound/pci/hda/hda_controller.c b/sound/pci/hda/hda_controller.c
index 2f3b7a35f2d9..56cafd12fa8a 100644
--- a/sound/pci/hda/hda_controller.c
+++ b/sound/pci/hda/hda_controller.c
@@ -792,21 +792,25 @@ static int azx_rirb_get_response(struct hdac_bus *bus, unsigned int addr,
 	struct hda_bus *hbus = &chip->bus;
 	unsigned long timeout;
 	unsigned long loopcounter;
-	int do_poll = 0;
+	wait_queue_entry_t wait;
 	bool warned = false;
 
+	init_wait_entry(&wait, 0);
  again:
 	timeout = jiffies + msecs_to_jiffies(1000);
 
 	for (loopcounter = 0;; loopcounter++) {
 		spin_lock_irq(&bus->reg_lock);
-		if (bus->polling_mode || do_poll)
+		if (!bus->polling_mode)
+			prepare_to_wait(&bus->rirb_waitq, &wait,
+					TASK_UNINTERRUPTIBLE);
+		if (bus->polling_mode)
 			snd_hdac_bus_update_rirb(bus);
 		if (!bus->rirb.cmds[addr]) {
-			if (!do_poll)
-				bus->poll_count = 0;
 			if (res)
 				*res = bus->rirb.res[addr]; /* the last value */
+			if (!bus->polling_mode)
+				finish_wait(&bus->rirb_waitq, &wait);
 			spin_unlock_irq(&bus->reg_lock);
 			return 0;
 		}
@@ -814,7 +818,9 @@ static int azx_rirb_get_response(struct hdac_bus *bus, unsigned int addr,
 		if (time_after(jiffies, timeout))
 			break;
 #define LOOP_COUNT_MAX	3000
-		if (hbus->needs_damn_long_delay ||
+		if (!bus->polling_mode) {
+			schedule_timeout(msecs_to_jiffies(2));
+		} else if (hbus->needs_damn_long_delay ||
 		    loopcounter > LOOP_COUNT_MAX) {
 			if (loopcounter > LOOP_COUNT_MAX && !warned) {
 				dev_dbg_ratelimited(chip->card->dev,
@@ -829,19 +835,12 @@ static int azx_rirb_get_response(struct hdac_bus *bus, unsigned int addr,
 		}
 	}
 
+	if (!bus->polling_mode)
+		finish_wait(&bus->rirb_waitq, &wait);
+
 	if (hbus->no_response_fallback)
 		return -EIO;
 
-	if (!bus->polling_mode && bus->poll_count < 2) {
-		dev_dbg(chip->card->dev,
-			"azx_get_response timeout, polling the codec once: last cmd=0x%08x\n",
-			bus->last_cmd[addr]);
-		do_poll = 1;
-		bus->poll_count++;
-		goto again;
-	}
-
-
 	if (!bus->polling_mode) {
 		dev_warn(chip->card->dev,
 			 "azx_get_response timeout, switching to polling mode: last cmd=0x%08x\n",