Task systemd-shutdow:1 blocked for more than 120 seconds when system shutdown

Hi Nvidia,

We are testing on/off againg test with L4T35.4.1, Orin NX 16GB, and custom carrier board.
It’s pass in AT mode but fail in ATX mode.

It’s our testing step:

  1. External custom board trigger system power on every minutes.
  2. crontab run shutdwon.sh script.
  3. shutdwon.sh sleep 120 sec and shutdown.
    repeat step 1~3.

We got following error log and system hang in shutdown and never boot again after power on and shutdown many hundred times.

[  243.212860] INFO: task systemd-shutdow:1 blocked for more than 120 seconds.
[  243.220039]       Tainted: G           OE     5.10.120-tegra #1
[  243.226142] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.234247] INFO: task kworker/4:1:57 blocked for more than 120 seconds.
[  243.241142]       Tainted: G           OE     5.10.120-tegra #1
[  243.247232] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.255342] INFO: task kworker/0:2:101 blocked for more than 120 seconds.
[  243.262324]       Tainted: G           OE     5.10.120-tegra #1
[  243.268422] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  364.044858] INFO: task systemd-shutdow:1 blocked for more than 241 seconds.
[  364.052025]       Tainted: G           OE     5.10.120-tegra #1
[  364.058126] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  364.066213] INFO: task kworker/4:1:57 blocked for more than 241 seconds.
[  364.073114]       Tainted: G           OE     5.10.120-tegra #1
[  364.079216] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  364.087302] INFO: task kworker/0:2:101 blocked for more than 241 seconds.
[  364.094285]       Tainted: G           OE     5.10.120-tegra #1
[  364.100383] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  484.876859] INFO: task systemd-shutdow:1 blocked for more than 362 seconds.
[  484.884032]       Tainted: G           OE     5.10.120-tegra #1
[  484.890135] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  484.898222] INFO: task kworker/4:1:57 blocked for more than 362 seconds.
[  484.905130]       Tainted: G           OE     5.10.120-tegra #1
[  484.911215] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  484.919300] INFO: task kworker/0:2:101 blocked for more than 362 seconds.
[  484.926284]       Tainted: G           OE     5.10.120-tegra #1
[  484.932370] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  605.708859] INFO: task systemd-shutdow:1 blocked for more than 483 seconds.
[  605.716021]       Tainted: G           OE     5.10.120-tegra #1
[  605.722108] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

Does it have some different with AX and ATX mode?
Thanks any help.

Are you able to reproduce this issue on NV devkit?

Yes, we reproduce it last weekend.
Orin Nano Dev Kit.
L4T35.4.1. (Pure source code. Just download and flash)
It stop reboot again at boot up 1083 times.
It’s the error log and crontab script.
OrinNanoDevKit_errorlog.txt (839.7 KB)
onOffTest.sh.log (1.2 KB)
This is python code to start crontab

        os.system('echo 0 > ' + LOG_DIR + 'tmp/onOffCounter')
        os.system('cp onOffTest.sh /etc/')
        os.system('chmod +x /etc/onOffTest.sh')
        current_time = datetime.datetime.now().strftime('%Y%m%d%H%M%S')
        os.system('(crontab -l 2>/dev/null; echo "@reboot /etc/onOffTest.sh ' + current_time + '") | crontab -')

Hi,

Please also check /var/log/syslog if anything else got printed during error case.

Hi Wayne,

I upload the syslog file to google drive. I will also check the error log too, thanks.

Hi Wilson,

If there is no obvious print there, please adding this patch and see if it will print the TASK_UNINTERRUPTIBLE process when error happened.

Please also add the print to kernel/kernel-5.10/kernel/hung_task.c

@@ -135,6 +135,8 @@ static void check_hung_task(struct task_struct *t, unsigned long timeout)
                pr_err("\"echo 0 > /proc/sys/kernel/hung_task_timeout_secs\""
                        " disables this message.\n");
                sched_show_task(t);
+               pr_crit("====DBG: Blocked tasks====<%s>\n", __func__);
+               show_state_filter(TASK_UNINTERRUPTIBLE);
                hung_task_show_lock = true;

You could also checked why previous sched_show_task didn’t print anything.

kernel/kernel-5.10/kernel/sched/core.c

I add your patch to kerenl and run the testing again. I will update the results, thanks.

Hi Wayne,

It didn’t show TASK_UNINTERRUPTIBLE.

[  243.171469] INFO: task systemd-shutdow:1 blocked for more than 120 seconds.
[  243.178656]       Tainted: G           OE     5.10.120-tegra #1
[  243.184749] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.192886] ====DBG: Blocked tasks====<check_hung_task>
[  243.198468] INFO: task kworker/0:0:5 blocked for more than 120 seconds.
[  243.205280]       Tainted: G           OE     5.10.120-tegra #1
[  243.211370] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.219466] ====DBG: Blocked tasks====<check_hung_task>
[  243.224978] INFO: task kworker/2:1:44 blocked for more than 120 seconds.
[  243.231873]       Tainted: G           OE     5.10.120-tegra #1
[  243.237955] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.246052] ====DBG: Blocked tasks====<check_hung_task>
[  364.003307] INFO: task systemd-shutdow:1 blocked for more than 241 seconds.
[  364.010484]       Tainted: G           OE     5.10.120-tegra #1
[  364.016572] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  364.024703] ====DBG: Blocked tasks====<check_hung_task>
[  364.030303] INFO: task kworker/0:0:5 blocked for more than 241 seconds.
[  364.037112]       Tainted: G           OE     5.10.120-tegra #1
[  364.043192] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  364.051286] ====DBG: Blocked tasks====<check_hung_task>
[  364.056788] INFO: task kworker/2:1:44 blocked for more than 241 seconds.
[  364.063686]       Tainted: G           OE     5.10.120-tegra #1
[  364.069773] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  364.077872] ====DBG: Blocked tasks====<check_hung_task>
[  484.835302] INFO: task systemd-shutdow:1 blocked for more than 362 seconds.
[  484.842482]       Tainted: G           OE     5.10.120-tegra #1
[  484.848575] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  484.856715] ====DBG: Blocked tasks====<check_hung_task>
[  484.862328] INFO: task kworker/0:0:5 blocked for more than 362 seconds.
[  484.869142]       Tainted: G           OE     5.10.120-tegra #1
[  484.875231] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  484.883325] ====DBG: Blocked tasks====<check_hung_task>
[  484.888823] INFO: task kworker/2:1:44 blocked for more than 362 seconds.
[  484.895724]       Tainted: G           OE     5.10.120-tegra #1
[  484.901811] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  484.909905] ====DBG: Blocked tasks====<check_hung_task>
[  605.667302] INFO: task systemd-shutdow:1 blocked for more than 483 seconds.
[  605.674478]       Tainted: G           OE     5.10.120-tegra #1
[  605.680583] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  605.688725] ====DBG: Blocked tasks====<check_hung_task>

OrinNanoDBG.txt (840.3 KB)

Hi,

Please try this patch.

diff --git a/kernel/rcu/tree_stall.h b/kernel/rcu/tree_stall.h
index 251a9af..94a6e9c 100644
--- a/kernel/rcu/tree_stall.h
+++ b/kernel/rcu/tree_stall.h
@@ -535,6 +535,10 @@
 	rcu_check_gp_kthread_starvation();
 
 	panic_on_rcu_stall();
+	pr_crit("====For debug only: Start Printing Blocked Tasks====<%s>\n", __func__);
+	console_loglevel = CONSOLE_LOGLEVEL_DEBUG;
+	show_state_filter(TASK_UNINTERRUPTIBLE);
+	pr_crit("====For debug only: End Printing Blocked Tasks====<%s>\n", __func__);
 
 	rcu_force_quiescent_state();  /* Kick them all. */
 }
@@ -580,6 +584,10 @@
 			   jiffies + 3 * rcu_jiffies_till_stall_check() + 3);
 	raw_spin_unlock_irqrestore_rcu_node(rnp, flags);
 
+	pr_crit("====For debug only: Start Printing Blocked Tasks====<%s>\n", __func__);
+	console_loglevel = CONSOLE_LOGLEVEL_DEBUG;
+	show_state_filter(TASK_UNINTERRUPTIBLE);
+	pr_crit("====For debug only: End Printing Blocked Tasks====<%s>\n", __func__);
 	panic_on_rcu_stall();
 
 	/*
diff --git a/kernel/watchdog.c b/kernel/watchdog.c
index 01bf977..1d237ff 100644
--- a/kernel/watchdog.c
+++ b/kernel/watchdog.c
@@ -416,10 +416,17 @@
 			dump_stack();
 
 		if (softlockup_all_cpu_backtrace) {
+			pr_crit("===For debug only: in softlockup_all_cpu_backtrace===<%s>\n", __func__);
+			console_loglevel = CONSOLE_LOGLEVEL_DEBUG;
 			trigger_allbutself_cpu_backtrace();
 			clear_bit_unlock(0, &soft_lockup_nmi_warn);
 		}
 
+		pr_crit("====For debug only: Start Printing Blocked Tasks====<%s>\n", __func__);
+		console_loglevel = CONSOLE_LOGLEVEL_DEBUG;
+		show_state_filter(TASK_UNINTERRUPTIBLE);
+		pr_crit("====For debug only: End Printing Blocked Tasks====<%s>\n", __func__);
+
 		add_taint(TAINT_SOFTLOCKUP, LOCKDEP_STILL_OK);
 		if (softlockup_panic)
 			panic("softlockup: hung tasks");

The patch sets the loglevel.

Hi
I check the kernel source code. The patch already in the code.
My kernel source code download command:

./source_sync.sh -t jetson_35.4.1

Please add the log level in previous patch as below.

@@ -135,6 +135,8 @@ static void check_hung_task(struct task_struct *t, unsigned long timeout)
                pr_err("\"echo 0 > /proc/sys/kernel/hung_task_timeout_secs\""
                        " disables this message.\n");
                sched_show_task(t);
+               pr_crit("====DBG: Blocked tasks====<%s>\n", __func__);
+               console_loglevel = CONSOLE_LOGLEVEL_DEBUG;
+               show_state_filter(TASK_UNINTERRUPTIBLE);
                hung_task_show_lock = true;
---------------------------------------------------

Hi Wayne,

This the log update.
OrinNanoDBG_20231011.txt (830.8 KB)

[  243.182037] INFO: task systemd-shutdow:1 blocked for more than 120 seconds.
[  243.189229]       Tainted: G           OE     5.10.120-tegra #3
[  243.195326] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.203512] ====DBG: Blocked tasks====<check_hung_task>
[  243.208892] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  243.217490] Call trace:
[  243.220011]  __switch_to+0xc8/0x120
[  243.223602]  __schedule+0x3d0/0x910
[  243.227193]  schedule+0x74/0x100
[  243.230516]  __pm_runtime_barrier+0x88/0x130
[  243.234913]  pm_runtime_barrier+0x5c/0xe0
[  243.239056]  device_shutdown+0xec/0x530
[  243.243001]  kernel_power_off+0x3c/0x80
[  243.246946]  __do_sys_reboot+0x154/0x230
[  243.250988]  __arm64_sys_reboot+0x2c/0x40
[  243.255117]  el0_svc_common.constprop.0+0x7c/0x1c0
[  243.260054]  do_el0_svc+0x34/0xa0
[  243.263466]  el0_svc+0x1c/0x30
[  243.266613]  el0_sync_handler+0xa8/0xb0
[  243.270555]  el0_sync+0x16c/0x180
[  243.273992] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  243.282593] Workqueue: pm pm_runtime_work
[  243.286720] Call trace:
[  243.289236]  __switch_to+0xc8/0x120
[  243.292825]  __schedule+0x3d0/0x910
[  243.296413]  schedule+0x74/0x100
[  243.299739]  schedule_timeout+0x2d4/0x330
[  243.303869]  wait_for_completion+0x88/0x110
[  243.308178]  __flush_work.isra.0+0x104/0x220
[  243.312576]  __cancel_work_timer+0x144/0x1b0
[  243.316970]  cancel_delayed_work_sync+0x24/0x30
[  243.321658]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  243.327570]  __rpm_callback+0xfc/0x1a0
[  243.331434]  rpm_callback+0x34/0xa0
[  243.335026]  rpm_suspend+0xe0/0x620
[  243.338613]  pm_runtime_work+0xbc/0xc0
[  243.342472]  process_one_work+0x1c0/0x4a0
[  243.346610]  worker_thread+0x50/0x420
[  243.350386]  kthread+0x148/0x170
[  243.353704]  ret_from_fork+0x10/0x18
[  243.357447] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  243.366055] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  243.372518] Call trace:
[  243.375039]  __switch_to+0xc8/0x120
[  243.378627]  __schedule+0x3d0/0x910
[  243.382224]  schedule+0x74/0x100
[  243.385541]  rpm_resume+0x154/0x740
[  243.389129]  __pm_runtime_resume+0x40/0x90
[  243.393353]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  243.399004]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  243.405021]  process_one_work+0x1c0/0x4a0
[  243.409147]  worker_thread+0x50/0x420
[  243.412911]  kthread+0x148/0x170
[  243.416234]  ret_from_fork+0x10/0x18
[  243.419941] INFO: task kworker/0:2:89 blocked for more than 121 seconds.
[  243.426844]       Tainted: G           OE     5.10.120-tegra #3
[  243.432946] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.441005] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  243.449603] Workqueue: pm pm_runtime_work
[  243.453729] Call trace:
[  243.456248]  __switch_to+0xc8/0x120
[  243.459838]  __schedule+0x3d0/0x910
[  243.463428]  schedule+0x74/0x100
[  243.466756]  schedule_timeout+0x2d4/0x330
[  243.470877]  wait_for_completion+0x88/0x110
[  243.475171]  __flush_work.isra.0+0x104/0x220
[  243.479570]  __cancel_work_timer+0x144/0x1b0
[  243.483969]  cancel_delayed_work_sync+0x24/0x30
[  243.488649]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  243.494579]  __rpm_callback+0xfc/0x1a0
[  243.498444]  rpm_callback+0x34/0xa0
[  243.502036]  rpm_suspend+0xe0/0x620
[  243.505626]  pm_runtime_work+0xbc/0xc0
[  243.509489]  process_one_work+0x1c0/0x4a0
[  243.513642]  worker_thread+0x50/0x420
[  243.517408]  kthread+0x148/0x170
[  243.520733]  ret_from_fork+0x10/0x18
[  243.524417] ====DBG: Blocked tasks====<check_hung_task>
[  243.529803] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  243.538404] Call trace:
[  243.540926]  __switch_to+0xc8/0x120
[  243.544529]  __schedule+0x3d0/0x910
[  243.548125]  schedule+0x74/0x100
[  243.551451]  __pm_runtime_barrier+0x88/0x130
[  243.555854]  pm_runtime_barrier+0x5c/0xe0
[  243.559989]  device_shutdown+0xec/0x530
[  243.563939]  kernel_power_off+0x3c/0x80
[  243.567887]  __do_sys_reboot+0x154/0x230
[  243.571922]  __arm64_sys_reboot+0x2c/0x40
[  243.576063]  el0_svc_common.constprop.0+0x7c/0x1c0
[  243.581000]  do_el0_svc+0x34/0xa0
[  243.584422]  el0_svc+0x1c/0x30
[  243.587571]  el0_sync_handler+0xa8/0xb0
[  243.591522]  el0_sync+0x16c/0x180
[  243.594946] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  243.603566] Workqueue: pm pm_runtime_work
[  243.607698] Call trace:
[  243.610226]  __switch_to+0xc8/0x120
[  243.613821]  __schedule+0x3d0/0x910
[  243.617423]  schedule+0x74/0x100
[  243.620759]  schedule_timeout+0x2d4/0x330
[  243.624891]  wait_for_completion+0x88/0x110
[  243.629191]  __flush_work.isra.0+0x104/0x220
[  243.633590]  __cancel_work_timer+0x144/0x1b0
[  243.637994]  cancel_delayed_work_sync+0x24/0x30
[  243.642673]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  243.648600]  __rpm_callback+0xfc/0x1a0
[  243.652457]  rpm_callback+0x34/0xa0
[  243.656053]  rpm_suspend+0xe0/0x620
[  243.659649]  pm_runtime_work+0xbc/0xc0
[  243.663519]  process_one_work+0x1c0/0x4a0
[  243.667656]  worker_thread+0x50/0x420
[  243.671437]  kthread+0x148/0x170
[  243.674762]  ret_from_fork+0x10/0x18
[  243.678473] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  243.687111] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  243.693582] Call trace:
[  243.696112]  __switch_to+0xc8/0x120
[  243.699713]  __schedule+0x3d0/0x910
[  243.703315]  schedule+0x74/0x100
[  243.706651]  rpm_resume+0x154/0x740
[  243.710250]  __pm_runtime_resume+0x40/0x90
[  243.714472]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  243.720152]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  243.726174]  process_one_work+0x1c0/0x4a0
[  243.730308]  worker_thread+0x50/0x420
[  243.734071]  kthread+0x148/0x170
[  243.737398]  ret_from_fork+0x10/0x18
[  243.741086] INFO: task kworker/5:4:409 blocked for more than 121 seconds.
[  243.748089]       Tainted: G           OE     5.10.120-tegra #3
[  243.754195] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.762270] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  243.770895] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  243.777355] Call trace:
[  243.779881]  __switch_to+0xc8/0x120
[  243.783481]  __schedule+0x3d0/0x910
[  243.787076]  schedule+0x74/0x100
[  243.790402]  rpm_resume+0x154/0x740
[  243.793995]  __pm_runtime_resume+0x40/0x90
[  243.798221]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  243.803895]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  243.809913]  process_one_work+0x1c0/0x4a0
[  243.814047]  worker_thread+0x50/0x420
[  243.817817]  kthread+0x148/0x170
[  243.821151]  ret_from_fork+0x10/0x18
[  243.824828] ====DBG: Blocked tasks====<check_hung_task>
[  243.830204] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  243.838822] Call trace:
[  243.841344]  __switch_to+0xc8/0x120
[  243.844943]  __schedule+0x3d0/0x910
[  243.848538]  schedule+0x74/0x100
[  243.851864]  __pm_runtime_barrier+0x88/0x130
[  243.856256]  pm_runtime_barrier+0x5c/0xe0
[  243.860396]  device_shutdown+0xec/0x530
[  243.864348]  kernel_power_off+0x3c/0x80
[  243.868305]  __do_sys_reboot+0x154/0x230
[  243.872350]  __arm64_sys_reboot+0x2c/0x40
[  243.876491]  el0_svc_common.constprop.0+0x7c/0x1c0
[  243.881441]  do_el0_svc+0x34/0xa0
[  243.884863]  el0_svc+0x1c/0x30
[  243.888013]  el0_sync_handler+0xa8/0xb0
[  243.891970]  el0_sync+0x16c/0x180
[  243.895396] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  243.904002] Workqueue: pm pm_runtime_work
[  243.908135] Call trace:
[  243.910672]  __switch_to+0xc8/0x120
[  243.914268]  __schedule+0x3d0/0x910
[  243.917862]  schedule+0x74/0x100
[  243.921195]  schedule_timeout+0x2d4/0x330
[  243.925332]  wait_for_completion+0x88/0x110
[  243.929637]  __flush_work.isra.0+0x104/0x220
[  243.934042]  __cancel_work_timer+0x144/0x1b0
[  243.938441]  cancel_delayed_work_sync+0x24/0x30
[  243.943127]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  243.949062]  __rpm_callback+0xfc/0x1a0
[  243.952935]  rpm_callback+0x34/0xa0
[  243.956537]  rpm_suspend+0xe0/0x620
[  243.960129]  pm_runtime_work+0xbc/0xc0
[  243.963997]  process_one_work+0x1c0/0x4a0
[  243.968138]  worker_thread+0x50/0x420
[  243.971918]  kthread+0x148/0x170
[  243.975249]  ret_from_fork+0x10/0x18
[  243.978954] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  243.987578] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  243.994035] Call trace:
[  243.996551]  __switch_to+0xc8/0x120
[  244.000146]  __schedule+0x3d0/0x910
[  244.003747]  schedule+0x74/0x100
[  244.007069]  rpm_resume+0x154/0x740
[  244.010665]  __pm_runtime_resume+0x40/0x90
[  244.014893]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  244.020561]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  244.026593]  process_one_work+0x1c0/0x4a0
[  244.030727]  worker_thread+0x50/0x420
[  244.034492]  kthread+0x148/0x170
[  244.037813]  ret_from_fork+0x10/0x18
[  366.062229] INFO: task systemd-shutdow:1 blocked for more than 243 seconds.
[  366.069426]       Tainted: G           OE     5.10.120-tegra #3
[  366.075532] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  366.083602] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  366.092207] Call trace:
[  366.094741]  __switch_to+0xc8/0x120
[  366.098344]  __schedule+0x3d0/0x910
[  366.101936]  schedule+0x74/0x100
[  366.105267]  __pm_runtime_barrier+0x88/0x130
[  366.109670]  pm_runtime_barrier+0x5c/0xe0
[  366.113799]  device_shutdown+0xec/0x530
[  366.117746]  kernel_power_off+0x3c/0x80
[  366.121689]  __do_sys_reboot+0x154/0x230
[  366.125730]  __arm64_sys_reboot+0x2c/0x40
[  366.129865]  el0_svc_common.constprop.0+0x7c/0x1c0
[  366.134803]  do_el0_svc+0x34/0xa0
[  366.138212]  el0_svc+0x1c/0x30
[  366.141350]  el0_sync_handler+0xa8/0xb0
[  366.145301]  el0_sync+0x16c/0x180
[  366.148712] ====DBG: Blocked tasks====<check_hung_task>
[  366.154092] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  366.162690] Call trace:
[  366.165208]  __switch_to+0xc8/0x120
[  366.168797]  __schedule+0x3d0/0x910
[  366.172386]  schedule+0x74/0x100
[  366.175708]  __pm_runtime_barrier+0x88/0x130
[  366.180103]  pm_runtime_barrier+0x5c/0xe0
[  366.184227]  device_shutdown+0xec/0x530
[  366.188169]  kernel_power_off+0x3c/0x80
[  366.192125]  __do_sys_reboot+0x154/0x230
[  366.196162]  __arm64_sys_reboot+0x2c/0x40
[  366.200290]  el0_svc_common.constprop.0+0x7c/0x1c0
[  366.205227]  do_el0_svc+0x34/0xa0
[  366.208636]  el0_svc+0x1c/0x30
[  366.211777]  el0_sync_handler+0xa8/0xb0
[  366.215724]  el0_sync+0x16c/0x180
[  366.219160] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  366.227764] Workqueue: pm pm_runtime_work
[  366.231893] Call trace:
[  366.234415]  __switch_to+0xc8/0x120
[  366.238000]  __schedule+0x3d0/0x910
[  366.241590]  schedule+0x74/0x100
[  366.244914]  schedule_timeout+0x2d4/0x330
[  366.249048]  wait_for_completion+0x88/0x110
[  366.253355]  __flush_work.isra.0+0x104/0x220
[  366.257753]  __cancel_work_timer+0x144/0x1b0
[  366.262154]  cancel_delayed_work_sync+0x24/0x30
[  366.266840]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  366.272769]  __rpm_callback+0xfc/0x1a0
[  366.276634]  rpm_callback+0x34/0xa0
[  366.280224]  rpm_suspend+0xe0/0x620
[  366.283814]  pm_runtime_work+0xbc/0xc0
[  366.287672]  process_one_work+0x1c0/0x4a0
[  366.291808]  worker_thread+0x50/0x420
[  366.295576]  kthread+0x148/0x170
[  366.298899]  ret_from_fork+0x10/0x18
[  366.302625] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  366.311235] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  366.317682] Call trace:
[  366.320205]  __switch_to+0xc8/0x120
[  366.323796]  __schedule+0x3d0/0x910
[  366.327386]  schedule+0x74/0x100
[  366.330713]  rpm_resume+0x154/0x740
[  366.334306]  __pm_runtime_resume+0x40/0x90
[  366.338529]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  366.344180]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  366.350200]  process_one_work+0x1c0/0x4a0
[  366.354336]  worker_thread+0x50/0x420
[  366.358100]  kthread+0x148/0x170
[  366.361421]  ret_from_fork+0x10/0x18
[  366.365123] INFO: task kworker/0:2:89 blocked for more than 244 seconds.
[  366.372036]       Tainted: G           OE     5.10.120-tegra #3
[  366.378129] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  366.386196] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  366.394821] Workqueue: pm pm_runtime_work
[  366.398953] Call trace:
[  366.401474]  __switch_to+0xc8/0x120
[  366.405079]  __schedule+0x3d0/0x910
[  366.408670]  schedule+0x74/0x100
[  366.412006]  schedule_timeout+0x2d4/0x330
[  366.416141]  wait_for_completion+0x88/0x110
[  366.420449]  __flush_work.isra.0+0x104/0x220
[  366.424848]  __cancel_work_timer+0x144/0x1b0
[  366.429249]  cancel_delayed_work_sync+0x24/0x30
[  366.433935]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  366.439872]  __rpm_callback+0xfc/0x1a0
[  366.443740]  rpm_callback+0x34/0xa0
[  366.447332]  rpm_suspend+0xe0/0x620
[  366.450932]  pm_runtime_work+0xbc/0xc0
[  366.454799]  process_one_work+0x1c0/0x4a0
[  366.458936]  worker_thread+0x50/0x420
[  366.462719]  kthread+0x148/0x170
[  366.466045]  ret_from_fork+0x10/0x18
[  366.469733] ====DBG: Blocked tasks====<check_hung_task>
[  366.475127] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  366.483746] Call trace:
[  366.486272]  __switch_to+0xc8/0x120
[  366.489863]  __schedule+0x3d0/0x910
[  366.493462]  schedule+0x74/0x100
[  366.496793]  __pm_runtime_barrier+0x88/0x130
[  366.501188]  pm_runtime_barrier+0x5c/0xe0
[  366.505324]  device_shutdown+0xec/0x530
[  366.509271]  kernel_power_off+0x3c/0x80
[  366.513223]  __do_sys_reboot+0x154/0x230
[  366.517255]  __arm64_sys_reboot+0x2c/0x40
[  366.521381]  el0_svc_common.constprop.0+0x7c/0x1c0
[  366.526331]  do_el0_svc+0x34/0xa0
[  366.529744]  el0_svc+0x1c/0x30
[  366.532891]  el0_sync_handler+0xa8/0xb0
[  366.536843]  el0_sync+0x16c/0x180
[  366.540265] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  366.548872] Workqueue: pm pm_runtime_work
[  366.553008] Call trace:
[  366.555533]  __switch_to+0xc8/0x120
[  366.559127]  __schedule+0x3d0/0x910
[  366.562725]  schedule+0x74/0x100
[  366.566057]  schedule_timeout+0x2d4/0x330
[  366.570191]  wait_for_completion+0x88/0x110
[  366.574498]  __flush_work.isra.0+0x104/0x220
[  366.578893]  __cancel_work_timer+0x144/0x1b0
[  366.583295]  cancel_delayed_work_sync+0x24/0x30
[  366.587979]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  366.593915]  __rpm_callback+0xfc/0x1a0
[  366.597784]  rpm_callback+0x34/0xa0
[  366.601380]  rpm_suspend+0xe0/0x620
[  366.604968]  pm_runtime_work+0xbc/0xc0
[  366.608834]  process_one_work+0x1c0/0x4a0
[  366.612969]  worker_thread+0x50/0x420
[  366.616740]  kthread+0x148/0x170
[  366.620070]  ret_from_fork+0x10/0x18
[  366.623768] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  366.632388] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  366.638856] Call trace:
[  366.641378]  __switch_to+0xc8/0x120
[  366.644970]  __schedule+0x3d0/0x910
[  366.648565]  schedule+0x74/0x100
[  366.651897]  rpm_resume+0x154/0x740
[  366.655498]  __pm_runtime_resume+0x40/0x90
[  366.659726]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  366.665381]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  366.671408]  process_one_work+0x1c0/0x4a0
[  366.675537]  worker_thread+0x50/0x420
[  366.679307]  kthread+0x148/0x170
[  366.682631]  ret_from_fork+0x10/0x18
[  366.686329] INFO: task kworker/5:4:409 blocked for more than 244 seconds.
[  366.693337]       Tainted: G           OE     5.10.120-tegra #3
[  366.699447] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  366.707521] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  366.716148] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  366.722612] Call trace:
[  366.725133]  __switch_to+0xc8/0x120
[  366.728725]  __schedule+0x3d0/0x910
[  366.732325]  schedule+0x74/0x100
[  366.735655]  rpm_resume+0x154/0x740
[  366.739247]  __pm_runtime_resume+0x40/0x90
[  366.743470]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  366.749140]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  366.755171]  process_one_work+0x1c0/0x4a0
[  366.759317]  worker_thread+0x50/0x420
[  366.763090]  kthread+0x148/0x170
[  366.766416]  ret_from_fork+0x10/0x18
[  366.770092] ====DBG: Blocked tasks====<check_hung_task>
[  366.775476] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  366.784080] Call trace:
[  366.786604]  __switch_to+0xc8/0x120
[  366.790197]  __schedule+0x3d0/0x910
[  366.793787]  schedule+0x74/0x100
[  366.797119]  __pm_runtime_barrier+0x88/0x130
[  366.801523]  pm_runtime_barrier+0x5c/0xe0
[  366.805658]  device_shutdown+0xec/0x530
[  366.809613]  kernel_power_off+0x3c/0x80
[  366.813567]  __do_sys_reboot+0x154/0x230
[  366.817611]  __arm64_sys_reboot+0x2c/0x40
[  366.821740]  el0_svc_common.constprop.0+0x7c/0x1c0
[  366.826690]  do_el0_svc+0x34/0xa0
[  366.830102]  el0_svc+0x1c/0x30
[  366.833246]  el0_sync_handler+0xa8/0xb0
[  366.837207]  el0_sync+0x16c/0x180
[  366.840630] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  366.849232] Workqueue: pm pm_runtime_work
[  366.853366] Call trace:
[  366.855890]  __switch_to+0xc8/0x120
[  366.859481]  __schedule+0x3d0/0x910
[  366.863082]  schedule+0x74/0x100
[  366.866414]  schedule_timeout+0x2d4/0x330
[  366.870548]  wait_for_completion+0x88/0x110
[  366.874853]  __flush_work.isra.0+0x104/0x220
[  366.879251]  __cancel_work_timer+0x144/0x1b0
[  366.883653]  cancel_delayed_work_sync+0x24/0x30
[  366.888344]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  366.894272]  __rpm_callback+0xfc/0x1a0
[  366.898140]  rpm_callback+0x34/0xa0
[  366.901725]  rpm_suspend+0xe0/0x620
[  366.905318]  pm_runtime_work+0xbc/0xc0
[  366.909193]  process_one_work+0x1c0/0x4a0
[  366.913341]  worker_thread+0x50/0x420
[  366.917121]  kthread+0x148/0x170
[  366.920447]  ret_from_fork+0x10/0x18
[  366.924153] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  366.932785] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  366.939247] Call trace:
[  366.941765]  __switch_to+0xc8/0x120
[  366.945371]  __schedule+0x3d0/0x910
[  366.948968]  schedule+0x74/0x100
[  366.952301]  rpm_resume+0x154/0x740
[  366.955902]  __pm_runtime_resume+0x40/0x90
[  366.960124]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  366.965794]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  366.971817]  process_one_work+0x1c0/0x4a0
[  366.975953]  worker_thread+0x50/0x420
[  366.979726]  kthread+0x148/0x170
[  366.983062]  ret_from_fork+0x10/0x18
[  488.942224] INFO: task systemd-shutdow:1 blocked for more than 366 seconds.
[  488.949416]       Tainted: G           OE     5.10.120-tegra #3
[  488.955522] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  488.963591] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  488.972197] Call trace:
[  488.974731]  __switch_to+0xc8/0x120
[  488.978336]  __schedule+0x3d0/0x910
[  488.981923]  schedule+0x74/0x100
[  488.985247]  __pm_runtime_barrier+0x88/0x130
[  488.989639]  pm_runtime_barrier+0x5c/0xe0
[  488.993775]  device_shutdown+0xec/0x530
[  488.997721]  kernel_power_off+0x3c/0x80
[  489.001668]  __do_sys_reboot+0x154/0x230
[  489.005698]  __arm64_sys_reboot+0x2c/0x40
[  489.009830]  el0_svc_common.constprop.0+0x7c/0x1c0
[  489.014764]  do_el0_svc+0x34/0xa0
[  489.018181]  el0_svc+0x1c/0x30
[  489.021316]  el0_sync_handler+0xa8/0xb0
[  489.025261]  el0_sync+0x16c/0x180
[  489.028671] ====DBG: Blocked tasks====<check_hung_task>
[  489.034046] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  489.042649] Call trace:
[  489.045172]  __switch_to+0xc8/0x120
[  489.048762]  __schedule+0x3d0/0x910
[  489.052357]  schedule+0x74/0x100
[  489.055684]  __pm_runtime_barrier+0x88/0x130
[  489.060074]  pm_runtime_barrier+0x5c/0xe0
[  489.064202]  device_shutdown+0xec/0x530
[  489.068152]  kernel_power_off+0x3c/0x80
[  489.072105]  __do_sys_reboot+0x154/0x230
[  489.076137]  __arm64_sys_reboot+0x2c/0x40
[  489.080262]  el0_svc_common.constprop.0+0x7c/0x1c0
[  489.085196]  do_el0_svc+0x34/0xa0
[  489.088613]  el0_svc+0x1c/0x30
[  489.091755]  el0_sync_handler+0xa8/0xb0
[  489.095704]  el0_sync+0x16c/0x180
[  489.099135] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  489.107734] Workqueue: pm pm_runtime_work
[  489.111865] Call trace:
[  489.114387]  __switch_to+0xc8/0x120
[  489.117971]  __schedule+0x3d0/0x910
[  489.121561]  schedule+0x74/0x100
[  489.124888]  schedule_timeout+0x2d4/0x330
[  489.129013]  wait_for_completion+0x88/0x110
[  489.133313]  __flush_work.isra.0+0x104/0x220
[  489.137714]  __cancel_work_timer+0x144/0x1b0
[  489.142110]  cancel_delayed_work_sync+0x24/0x30
[  489.146795]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  489.152722]  __rpm_callback+0xfc/0x1a0
[  489.156579]  rpm_callback+0x34/0xa0
[  489.160165]  rpm_suspend+0xe0/0x620
[  489.163755]  pm_runtime_work+0xbc/0xc0
[  489.167611]  process_one_work+0x1c0/0x4a0
[  489.171743]  worker_thread+0x50/0x420
[  489.175511]  kthread+0x148/0x170
[  489.178837]  ret_from_fork+0x10/0x18
[  489.182555] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  489.191162] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  489.197604] Call trace:
[  489.200126]  __switch_to+0xc8/0x120
[  489.203727]  __schedule+0x3d0/0x910
[  489.207316]  schedule+0x74/0x100
[  489.210641]  rpm_resume+0x154/0x740
[  489.214241]  __pm_runtime_resume+0x40/0x90
[  489.218470]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  489.224142]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  489.230165]  process_one_work+0x1c0/0x4a0
[  489.234299]  worker_thread+0x50/0x420
[  489.238068]  kthread+0x148/0x170
[  489.241396]  ret_from_fork+0x10/0x18
[  489.245093] INFO: task kworker/0:2:89 blocked for more than 366 seconds.
[  489.252007]       Tainted: G           OE     5.10.120-tegra #3
[  489.258123] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  489.266196] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  489.274807] Workqueue: pm pm_runtime_work
[  489.278933] Call trace:
[  489.281453]  __switch_to+0xc8/0x120
[  489.285057]  __schedule+0x3d0/0x910
[  489.288656]  schedule+0x74/0x100
[  489.291992]  schedule_timeout+0x2d4/0x330
[  489.296123]  wait_for_completion+0x88/0x110
[  489.300431]  __flush_work.isra.0+0x104/0x220
[  489.304827]  __cancel_work_timer+0x144/0x1b0
[  489.309222]  cancel_delayed_work_sync+0x24/0x30
[  489.313911]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  489.319856]  __rpm_callback+0xfc/0x1a0
[  489.323726]  rpm_callback+0x34/0xa0
[  489.327331]  rpm_suspend+0xe0/0x620
[  489.330933]  pm_runtime_work+0xbc/0xc0
[  489.334802]  process_one_work+0x1c0/0x4a0
[  489.338950]  worker_thread+0x50/0x420
[  489.342731]  kthread+0x148/0x170
[  489.346056]  ret_from_fork+0x10/0x18
[  489.349742] ====DBG: Blocked tasks====<check_hung_task>
[  489.355144] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  489.363762] Call trace:
[  489.366282]  __switch_to+0xc8/0x120
[  489.369870]  __schedule+0x3d0/0x910
[  489.373462]  schedule+0x74/0x100
[  489.376787]  __pm_runtime_barrier+0x88/0x130
[  489.381185]  pm_runtime_barrier+0x5c/0xe0
[  489.385315]  device_shutdown+0xec/0x530
[  489.389264]  kernel_power_off+0x3c/0x80
[  489.393215]  __do_sys_reboot+0x154/0x230
[  489.397250]  __arm64_sys_reboot+0x2c/0x40
[  489.401386]  el0_svc_common.constprop.0+0x7c/0x1c0
[  489.406333]  do_el0_svc+0x34/0xa0
[  489.409741]  el0_svc+0x1c/0x30
[  489.412889]  el0_sync_handler+0xa8/0xb0
[  489.416844]  el0_sync+0x16c/0x180
[  489.420270] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  489.428891] Workqueue: pm pm_runtime_work
[  489.433014] Call trace:
[  489.435537]  __switch_to+0xc8/0x120
[  489.439132]  __schedule+0x3d0/0x910
[  489.442732]  schedule+0x74/0x100
[  489.446063]  schedule_timeout+0x2d4/0x330
[  489.450195]  wait_for_completion+0x88/0x110
[  489.454505]  __flush_work.isra.0+0x104/0x220
[  489.458903]  __cancel_work_timer+0x144/0x1b0
[  489.463305]  cancel_delayed_work_sync+0x24/0x30
[  489.467990]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  489.473921]  __rpm_callback+0xfc/0x1a0
[  489.477787]  rpm_callback+0x34/0xa0
[  489.481380]  rpm_suspend+0xe0/0x620
[  489.484978]  pm_runtime_work+0xbc/0xc0
[  489.488841]  process_one_work+0x1c0/0x4a0
[  489.492977]  worker_thread+0x50/0x420
[  489.496751]  kthread+0x148/0x170
[  489.500077]  ret_from_fork+0x10/0x18
[  489.503775] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  489.512408] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  489.518876] Call trace:
[  489.521398]  __switch_to+0xc8/0x120
[  489.524997]  __schedule+0x3d0/0x910
[  489.528596]  schedule+0x74/0x100
[  489.531926]  rpm_resume+0x154/0x740
[  489.535526]  __pm_runtime_resume+0x40/0x90
[  489.539748]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  489.545418]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  489.551437]  process_one_work+0x1c0/0x4a0
[  489.555577]  worker_thread+0x50/0x420
[  489.559342]  kthread+0x148/0x170
[  489.562668]  ret_from_fork+0x10/0x18
[  489.566355] INFO: task kworker/5:4:409 blocked for more than 367 seconds.
[  489.573360]       Tainted: G           OE     5.10.120-tegra #3
[  489.579468] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  489.587540] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  489.596165] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  489.602624] Call trace:
[  489.605144]  __switch_to+0xc8/0x120
[  489.608742]  __schedule+0x3d0/0x910
[  489.612333]  schedule+0x74/0x100
[  489.615659]  rpm_resume+0x154/0x740
[  489.619258]  __pm_runtime_resume+0x40/0x90
[  489.623484]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  489.629152]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  489.635185]  process_one_work+0x1c0/0x4a0
[  489.639323]  worker_thread+0x50/0x420
[  489.643092]  kthread+0x148/0x170
[  489.646427]  ret_from_fork+0x10/0x18
[  489.650109] ====DBG: Blocked tasks====<check_hung_task>
[  489.655509] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  489.664125] Call trace:
[  489.666649]  __switch_to+0xc8/0x120
[  489.670241]  __schedule+0x3d0/0x910
[  489.673828]  schedule+0x74/0x100
[  489.677151]  __pm_runtime_barrier+0x88/0x130
[  489.681550]  pm_runtime_barrier+0x5c/0xe0
[  489.685688]  device_shutdown+0xec/0x530
[  489.689639]  kernel_power_off+0x3c/0x80
[  489.693587]  __do_sys_reboot+0x154/0x230
[  489.697624]  __arm64_sys_reboot+0x2c/0x40
[  489.701763]  el0_svc_common.constprop.0+0x7c/0x1c0
[  489.706722]  do_el0_svc+0x34/0xa0
[  489.710131]  el0_svc+0x1c/0x30
[  489.713273]  el0_sync_handler+0xa8/0xb0
[  489.717226]  el0_sync+0x16c/0x180
[  489.720648] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  489.729272] Workqueue: pm pm_runtime_work
[  489.733397] Call trace:
[  489.735927]  __switch_to+0xc8/0x120
[  489.739526]  __schedule+0x3d0/0x910
[  489.743138]  schedule+0x74/0x100
[  489.746474]  schedule_timeout+0x2d4/0x330
[  489.750604]  wait_for_completion+0x88/0x110
[  489.754916]  __flush_work.isra.0+0x104/0x220
[  489.759318]  __cancel_work_timer+0x144/0x1b0
[  489.763730]  cancel_delayed_work_sync+0x24/0x30
[  489.768407]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  489.774350]  __rpm_callback+0xfc/0x1a0
[  489.778214]  rpm_callback+0x34/0xa0
[  489.781810]  rpm_suspend+0xe0/0x620
[  489.785410]  pm_runtime_work+0xbc/0xc0
[  489.789279]  process_one_work+0x1c0/0x4a0
[  489.793416]  worker_thread+0x50/0x420
[  489.797195]  kthread+0x148/0x170
[  489.800524]  ret_from_fork+0x10/0x18
[  489.804222] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  489.812834] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  489.819292] Call trace:
[  489.821815]  __switch_to+0xc8/0x120
[  489.825413]  __schedule+0x3d0/0x910
[  489.829015]  schedule+0x74/0x100
[  489.832343]  rpm_resume+0x154/0x740
[  489.835938]  __pm_runtime_resume+0x40/0x90
[  489.840166]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  489.845821]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  489.851852]  process_one_work+0x1c0/0x4a0
[  489.855988]  worker_thread+0x50/0x420
[  489.859756]  kthread+0x148/0x170
[  489.863082]  ret_from_fork+0x10/0x18
[  611.822032] INFO: task systemd-shutdow:1 blocked for more than 489 seconds.
[  611.829223]       Tainted: G           OE     5.10.120-tegra #3
[  611.835332] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  611.843395] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  611.851994] Call trace:
[  611.854532]  __switch_to+0xc8/0x120
[  611.858137]  __schedule+0x3d0/0x910
[  611.861723]  schedule+0x74/0x100
[  611.865052]  __pm_runtime_barrier+0x88/0x130
[  611.869444]  pm_runtime_barrier+0x5c/0xe0
[  611.873573]  device_shutdown+0xec/0x530
[  611.877520]  kernel_power_off+0x3c/0x80
[  611.881471]  __do_sys_reboot+0x154/0x230
[  611.885501]  __arm64_sys_reboot+0x2c/0x40
[  611.889629]  el0_svc_common.constprop.0+0x7c/0x1c0
[  611.894566]  do_el0_svc+0x34/0xa0
[  611.897974]  el0_svc+0x1c/0x30
[  611.901118]  el0_sync_handler+0xa8/0xb0
[  611.905066]  el0_sync+0x16c/0x180
[  611.908477] ====DBG: Blocked tasks====<check_hung_task>
[  611.913857] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000000
[  611.922466] Call trace:
[  611.924983]  __switch_to+0xc8/0x120
[  611.928573]  __schedule+0x3d0/0x910
[  611.932173]  schedule+0x74/0x100
[  611.935499]  __pm_runtime_barrier+0x88/0x130
[  611.939901]  pm_runtime_barrier+0x5c/0xe0
[  611.944024]  device_shutdown+0xec/0x530
[  611.947969]  kernel_power_off+0x3c/0x80
[  611.951911]  __do_sys_reboot+0x154/0x230
[  611.955948]  __arm64_sys_reboot+0x2c/0x40
[  611.960077]  el0_svc_common.constprop.0+0x7c/0x1c0
[  611.965018]  do_el0_svc+0x34/0xa0
[  611.968431]  el0_svc+0x1c/0x30
[  611.971575]  el0_sync_handler+0xa8/0xb0
[  611.975518]  el0_sync+0x16c/0x180
[  611.978950] task:kworker/0:2     state:D stack:    0 pid:   89 ppid:     2 flags:0x00000028
[  611.987552] Workqueue: pm pm_runtime_work
[  611.991677] Call trace:
[  611.994197]  __switch_to+0xc8/0x120
[  611.997789]  __schedule+0x3d0/0x910
[  612.001378]  schedule+0x74/0x100
[  612.004706]  schedule_timeout+0x2d4/0x330
[  612.008836]  wait_for_completion+0x88/0x110
[  612.013136]  __flush_work.isra.0+0x104/0x220
[  612.017529]  __cancel_work_timer+0x144/0x1b0
[  612.021924]  cancel_delayed_work_sync+0x24/0x30
[  612.026608]  snd_hda_codec_pcm_put+0xc0/0x170 [snd_hda_codec]
[  612.032524]  __rpm_callback+0xfc/0x1a0
[  612.036387]  rpm_callback+0x34/0xa0
[  612.039982]  rpm_suspend+0xe0/0x620
[  612.043572]  pm_runtime_work+0xbc/0xc0
[  612.047437]  process_one_work+0x1c0/0x4a0
[  612.051574]  worker_thread+0x50/0x420
[  612.055346]  kthread+0x148/0x170
[  612.058668]  ret_from_fork+0x10/0x18
[  612.062391] task:kworker/5:4     state:D stack:    0 pid:  409 ppid:     2 flags:0x00000028
[  612.070994] Workqueue: events snd_hda_codec_pcm_new [snd_hda_codec]
[  612.077451] Call trace:
[  612.079972]  __switch_to+0xc8/0x120
[  612.083563]  __schedule+0x3d0/0x910
[  612.087157]  schedule+0x74/0x100
[  612.090480]  rpm_resume+0x154/0x740
[  612.094075]  __pm_runtime_resume+0x40/0x90
[  612.098300]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  612.103968]  snd_hda_codec_pcm_new+0x274/0x410 [snd_hda_codec]
[  612.109999]  process_one_work+0x1c0/0x4a0
[  612.114130]  worker_thread+0x50/0x420
[  612.117902]  kthread+0x148/0x170
[  612.121232]  ret_from_fork+0x10/0x18

it looks like issue is from HDA driver.

Please attach this patch to kernel.
0001-UPSTREAM-5.15-ALSA-hda-Suspend-codec-at-shutdown.patch (3.0 KB)

Hi Wayne,
The patch doesn’t fix the issue.

I have added log in the function ( hda_codec_driver_shutdown and snd_hda_codec_shutdown).
It shows in the normal shutdown. (Wilson add …)

OrinNanoL4T3541 login: [   20.040555] audit: type=1326 audit(1697121268.682:3): auid=4294967295 uid=0 gid=0 ses=4294967295 subjernel pid=1878 comm="cupsd" exe="/snap/cups/981/sbin/cupsd" sig=0 arch=c00000b7 syscall=55 compat=0 ip=0xffffb1118f4c code=0x500
[   20.066067] audit: type=1326 audit(1697121268.710:4): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=1989 comm="ps-browsed" exe="/snap/cups/981/sbin/cups-browsed" sig=0 arch=c00000b7 syscall=274 compat=0 ip=0xffffb3f71a68 code=0x50000
[   75.886592] audit: type=1326 audit(1697121405.442:5): auid=4294967295 uid=0 gid=0 ses=4294967295 subj=kernel pid=1878 comm="psd" exe="/snap/cups/981/sbin/cupsd" sig=0 arch=c00000b7 syscall=55 compat=0 ip=0xffffb1118f4c code=0x50000
[   80.937008] ====Wilson add: DBG: Blocked tasks====<hda_codec_driver_shutdown>
[   80.944404] ====Wilson add: DBG: Blocked tasks====<snd_hda_codec_shutdown>
[   81.594708] nvgpu: 17000000.ga10b      ga10b_intr_log_pending_intrs:306  [ERR]  Pending TOP[0]: 0x00000004, LEAF[4]: 0x110000
[   81.607569] arm-smmu 8000000.iommu: disabling translation
[   81.613266] arm-smmu 10000000.iommu: disabling translation
[   81.618958] arm-smmu 12000000.iommu: disabling translation
[   81.657560] CPU1: shutdown
[   81.677330] CPU2: shutdown
[   81.697288] CPU3: shutdown
[   81.720986] CPU4: shutdown
[   81.741623] CPU5: shutdown
[   81.74▒▒▒▒6091] reboot: P▒▒Shutdown state requested 0
Shutting down syste▒▒

But it doesn’t show the log I added when the issue happened.
The system doesn’t into the hda_codec_shutdown function when issue happend.

[  243.170328] INFO: task systemd-shutdow:1 blocked for more than 120 seconds.
[  243.177510]       Tainted: G           OE     5.10.120-tegra #4
[  243.183597] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.191741] ====DBG: Blocked tasks====<check_hung_task>
[  243.197109] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  243.205697] Call trace:
[  243.208220]  __switch_to+0xc8/0x120
[  243.211806]  __schedule+0x3d0/0x910
[  243.215394]  schedule+0x74/0x100
[  243.218717]  __pm_runtime_barrier+0x88/0x130
[  243.223108]  pm_runtime_barrier+0x5c/0xe0
[  243.227227]  device_shutdown+0xec/0x530
[  243.231175]  kernel_power_off+0x3c/0x80
[  243.235126]  __do_sys_reboot+0x154/0x230
[  243.239149]  __arm64_sys_reboot+0x2c/0x40
[  243.243274]  el0_svc_common.constprop.0+0x7c/0x1c0
[  243.248217]  do_el0_svc+0x34/0xa0
[  243.251625]  el0_svc+0x1c/0x30
[  243.254769]  el0_sync_handler+0xa8/0xb0
[  243.258708]  el0_sync+0x16c/0x180
[  243.262165] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  243.270768] Workqueue: pm pm_runtime_work
[  243.274901] Call trace:
[  243.277409]  __switch_to+0xc8/0x120
[  243.280992]  __schedule+0x3d0/0x910
[  243.284589]  schedule+0x74/0x100
[  243.287916]  schedule_timeout+0x2d4/0x330
[  243.292041]  wait_for_completion+0x88/0x110
[  243.296344]  __flush_work.isra.0+0x104/0x220
[  243.300733]  __cancel_work_timer+0x144/0x1b0
[  243.305126]  cancel_delayed_work_sync+0x24/0x30
[  243.309801]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  243.315982]  __rpm_callback+0xfc/0x1a0
[  243.319838]  rpm_callback+0x34/0xa0
[  243.323432]  rpm_suspend+0xe0/0x620
[  243.327015]  pm_runtime_work+0xbc/0xc0
[  243.330872]  process_one_work+0x1c0/0x4a0
[  243.334999]  worker_thread+0x50/0x420
[  243.338760]  kthread+0x148/0x170
[  243.342083]  ret_from_fork+0x10/0x18
[  243.345763] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  243.354364] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  243.360456] Call trace:
[  243.362975]  __switch_to+0xc8/0x120
[  243.366559]  __schedule+0x3d0/0x910
[  243.370140]  schedule+0x74/0x100
[  243.373458]  rpm_resume+0x154/0x740
[  243.377054]  __pm_runtime_resume+0x40/0x90
[  243.381272]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  243.386913]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  243.392378]  process_one_work+0x1c0/0x4a0
[  243.396497]  worker_thread+0x50/0x420
[  243.400253]  kthread+0x148/0x170
[  243.403573]  ret_from_fork+0x10/0x18
[  243.407291] INFO: task kworker/1:8:144 blocked for more than 121 seconds.
[  243.414276]       Tainted: G           OE     5.10.120-tegra #4
[  243.420365] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.428418] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  243.437020] Workqueue: pm pm_runtime_work
[  243.441145] Call trace:
[  243.443662]  __switch_to+0xc8/0x120
[  243.447249]  __schedule+0x3d0/0x910
[  243.450838]  schedule+0x74/0x100
[  243.454156]  schedule_timeout+0x2d4/0x330
[  243.458280]  wait_for_completion+0x88/0x110
[  243.462578]  __flush_work.isra.0+0x104/0x220
[  243.466971]  __cancel_work_timer+0x144/0x1b0
[  243.471356]  cancel_delayed_work_sync+0x24/0x30
[  243.476021]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  243.482197]  __rpm_callback+0xfc/0x1a0
[  243.486056]  rpm_callback+0x34/0xa0
[  243.489641]  rpm_suspend+0xe0/0x620
[  243.493225]  pm_runtime_work+0xbc/0xc0
[  243.497086]  process_one_work+0x1c0/0x4a0
[  243.501208]  worker_thread+0x50/0x420
[  243.504965]  kthread+0x148/0x170
[  243.508285]  ret_from_fork+0x10/0x18
[  243.511962] ====DBG: Blocked tasks====<check_hung_task>
[  243.517342] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  243.525931] Call trace:
[  243.528450]  __switch_to+0xc8/0x120
[  243.532036]  __schedule+0x3d0/0x910
[  243.535626]  schedule+0x74/0x100
[  243.538950]  __pm_runtime_barrier+0x88/0x130
[  243.543340]  pm_runtime_barrier+0x5c/0xe0
[  243.547468]  device_shutdown+0xec/0x530
[  243.551407]  kernel_power_off+0x3c/0x80
[  243.555346]  __do_sys_reboot+0x154/0x230
[  243.559376]  __arm64_sys_reboot+0x2c/0x40
[  243.563501]  el0_svc_common.constprop.0+0x7c/0x1c0
[  243.568429]  do_el0_svc+0x34/0xa0
[  243.571833]  el0_svc+0x1c/0x30
[  243.574968]  el0_sync_handler+0xa8/0xb0
[  243.578910]  el0_sync+0x16c/0x180
[  243.582324] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  243.590921] Workqueue: pm pm_runtime_work
[  243.595041] Call trace:
[  243.597557]  __switch_to+0xc8/0x120
[  243.601151]  __schedule+0x3d0/0x910
[  243.604735]  schedule+0x74/0x100
[  243.608059]  schedule_timeout+0x2d4/0x330
[  243.612186]  wait_for_completion+0x88/0x110
[  243.616484]  __flush_work.isra.0+0x104/0x220
[  243.620880]  __cancel_work_timer+0x144/0x1b0
[  243.625269]  cancel_delayed_work_sync+0x24/0x30
[  243.629937]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  243.636110]  __rpm_callback+0xfc/0x1a0
[  243.639958]  rpm_callback+0x34/0xa0
[  243.643543]  rpm_suspend+0xe0/0x620
[  243.647128]  pm_runtime_work+0xbc/0xc0
[  243.650986]  process_one_work+0x1c0/0x4a0
[  243.655108]  worker_thread+0x50/0x420
[  243.658868]  kthread+0x148/0x170
[  243.662184]  ret_from_fork+0x10/0x18
[  243.665856] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  243.674459] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  243.680558] Call trace:
[  243.683081]  __switch_to+0xc8/0x120
[  243.686668]  __schedule+0x3d0/0x910
[  243.690252]  schedule+0x74/0x100
[  243.693566]  rpm_resume+0x154/0x740
[  243.697148]  __pm_runtime_resume+0x40/0x90
[  243.701364]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  243.707016]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  243.712481]  process_one_work+0x1c0/0x4a0
[  243.716606]  worker_thread+0x50/0x420
[  243.720362]  kthread+0x148/0x170
[  243.723677]  ret_from_fork+0x10/0x18
[  243.727355] INFO: task kworker/3:3:156 blocked for more than 121 seconds.
[  243.734345]       Tainted: G           OE     5.10.120-tegra #4
[  243.740447] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  243.748506] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  243.757101] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  243.763200] Call trace:
[  243.765724]  __switch_to+0xc8/0x120
[  243.769308]  __schedule+0x3d0/0x910
[  243.772896]  schedule+0x74/0x100
[  243.776212]  rpm_resume+0x154/0x740
[  243.779796]  __pm_runtime_resume+0x40/0x90
[  243.784005]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  243.789667]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  243.795140]  process_one_work+0x1c0/0x4a0
[  243.799261]  worker_thread+0x50/0x420
[  243.803018]  kthread+0x148/0x170
[  243.806335]  ret_from_fork+0x10/0x18
[  243.810009] ====DBG: Blocked tasks====<check_hung_task>
[  243.815383] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  243.823978] Call trace:
[  243.826493]  __switch_to+0xc8/0x120
[  243.830074]  __schedule+0x3d0/0x910
[  243.833660]  schedule+0x74/0x100
[  243.836976]  __pm_runtime_barrier+0x88/0x130
[  243.841366]  pm_runtime_barrier+0x5c/0xe0
[  243.845487]  device_shutdown+0xec/0x530
[  243.849423]  kernel_power_off+0x3c/0x80
[  243.853368]  __do_sys_reboot+0x154/0x230
[  243.857402]  __arm64_sys_reboot+0x2c/0x40
[  243.861521]  el0_svc_common.constprop.0+0x7c/0x1c0
[  243.866461]  do_el0_svc+0x34/0xa0
[  243.869874]  el0_svc+0x1c/0x30
[  243.873012]  el0_sync_handler+0xa8/0xb0
[  243.876953]  el0_sync+0x16c/0x180
[  243.880376] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  243.888977] Workqueue: pm pm_runtime_work
[  243.893102] Call trace:
[  243.895621]  __switch_to+0xc8/0x120
[  243.899211]  __schedule+0x3d0/0x910
[  243.902805]  schedule+0x74/0x100
[  243.906122]  schedule_timeout+0x2d4/0x330
[  243.910246]  wait_for_completion+0x88/0x110
[  243.914552]  __flush_work.isra.0+0x104/0x220
[  243.918946]  __cancel_work_timer+0x144/0x1b0
[  243.923336]  cancel_delayed_work_sync+0x24/0x30
[  243.928012]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  243.934200]  __rpm_callback+0xfc/0x1a0
[  243.938053]  rpm_callback+0x34/0xa0
[  243.941636]  rpm_suspend+0xe0/0x620
[  243.945219]  pm_runtime_work+0xbc/0xc0
[  243.949075]  process_one_work+0x1c0/0x4a0
[  243.953210]  worker_thread+0x50/0x420
[  243.956971]  kthread+0x148/0x170
[  243.960289]  ret_from_fork+0x10/0x18
[  243.963963] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  243.972556] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  243.978639] Call trace:
[  243.981151]  __switch_to+0xc8/0x120
[  243.984738]  __schedule+0x3d0/0x910
[  243.988323]  schedule+0x74/0x100
[  243.991642]  rpm_resume+0x154/0x740
[  243.995228]  __pm_runtime_resume+0x40/0x90
[  243.999439]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  244.005082]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  244.010544]  process_one_work+0x1c0/0x4a0
[  244.014661]  worker_thread+0x50/0x420
[  244.018422]  kthread+0x148/0x170
[  244.021739]  ret_from_fork+0x10/0x18
[  366.050325] INFO: task systemd-shutdow:1 blocked for more than 243 seconds.
[  366.057501]       Tainted: G           OE     5.10.120-tegra #4
[  366.063585] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  366.071642] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  366.080238] Call trace:
[  366.082771]  __switch_to+0xc8/0x120
[  366.086365]  __schedule+0x3d0/0x910
[  366.089947]  schedule+0x74/0x100
[  366.093270]  __pm_runtime_barrier+0x88/0x130
[  366.097662]  pm_runtime_barrier+0x5c/0xe0
[  366.101783]  device_shutdown+0xec/0x530
[  366.105725]  kernel_power_off+0x3c/0x80
[  366.109668]  __do_sys_reboot+0x154/0x230
[  366.113698]  __arm64_sys_reboot+0x2c/0x40
[  366.117824]  el0_svc_common.constprop.0+0x7c/0x1c0
[  366.122757]  do_el0_svc+0x34/0xa0
[  366.126173]  el0_svc+0x1c/0x30
[  366.129315]  el0_sync_handler+0xa8/0xb0
[  366.133252]  el0_sync+0x16c/0x180
[  366.136669] ====DBG: Blocked tasks====<check_hung_task>
[  366.142051] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  366.150641] Call trace:
[  366.153159]  __switch_to+0xc8/0x120
[  366.156743]  __schedule+0x3d0/0x910
[  366.160327]  schedule+0x74/0x100
[  366.163652]  __pm_runtime_barrier+0x88/0x130
[  366.168042]  pm_runtime_barrier+0x5c/0xe0
[  366.172160]  device_shutdown+0xec/0x530
[  366.176109]  kernel_power_off+0x3c/0x80
[  366.180057]  __do_sys_reboot+0x154/0x230
[  366.184083]  __arm64_sys_reboot+0x2c/0x40
[  366.188212]  el0_svc_common.constprop.0+0x7c/0x1c0
[  366.193139]  do_el0_svc+0x34/0xa0
[  366.196544]  el0_svc+0x1c/0x30
[  366.199682]  el0_sync_handler+0xa8/0xb0
[  366.203621]  el0_sync+0x16c/0x180
[  366.207069] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  366.215659] Workqueue: pm pm_runtime_work
[  366.219775] Call trace:
[  366.222294]  __switch_to+0xc8/0x120
[  366.225879]  __schedule+0x3d0/0x910
[  366.229463]  schedule+0x74/0x100
[  366.232785]  schedule_timeout+0x2d4/0x330
[  366.236902]  wait_for_completion+0x88/0x110
[  366.241203]  __flush_work.isra.0+0x104/0x220
[  366.245592]  __cancel_work_timer+0x144/0x1b0
[  366.249985]  cancel_delayed_work_sync+0x24/0x30
[  366.254660]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  366.260834]  __rpm_callback+0xfc/0x1a0
[  366.264689]  rpm_callback+0x34/0xa0
[  366.268278]  rpm_suspend+0xe0/0x620
[  366.271869]  pm_runtime_work+0xbc/0xc0
[  366.275721]  process_one_work+0x1c0/0x4a0
[  366.279848]  worker_thread+0x50/0x420
[  366.283605]  kthread+0x148/0x170
[  366.286922]  ret_from_fork+0x10/0x18
[  366.290603] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  366.299199] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  366.305282] Call trace:
[  366.307797]  __switch_to+0xc8/0x120
[  366.311383]  __schedule+0x3d0/0x910
[  366.314970]  schedule+0x74/0x100
[  366.318289]  rpm_resume+0x154/0x740
[  366.321873]  __pm_runtime_resume+0x40/0x90
[  366.326086]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  366.331730]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  366.337192]  process_one_work+0x1c0/0x4a0
[  366.341312]  worker_thread+0x50/0x420
[  366.345075]  kthread+0x148/0x170
[  366.348403]  ret_from_fork+0x10/0x18
[  366.352109] INFO: task kworker/1:8:144 blocked for more than 244 seconds.
[  366.359096]       Tainted: G           OE     5.10.120-tegra #4
[  366.365197] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  366.373259] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  366.381848] Workqueue: pm pm_runtime_work
[  366.385969] Call trace:
[  366.388486]  __switch_to+0xc8/0x120
[  366.392069]  __schedule+0x3d0/0x910
[  366.395663]  schedule+0x74/0x100
[  366.398981]  schedule_timeout+0x2d4/0x330
[  366.403100]  wait_for_completion+0x88/0x110
[  366.407399]  __flush_work.isra.0+0x104/0x220
[  366.411784]  __cancel_work_timer+0x144/0x1b0
[  366.416175]  cancel_delayed_work_sync+0x24/0x30
[  366.420842]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  366.427015]  __rpm_callback+0xfc/0x1a0
[  366.430867]  rpm_callback+0x34/0xa0
[  366.434453]  rpm_suspend+0xe0/0x620
[  366.438035]  pm_runtime_work+0xbc/0xc0
[  366.441892]  process_one_work+0x1c0/0x4a0
[  366.446018]  worker_thread+0x50/0x420
[  366.449782]  kthread+0x148/0x170
[  366.453106]  ret_from_fork+0x10/0x18
[  366.456785] ====DBG: Blocked tasks====<check_hung_task>
[  366.462161] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  366.470749] Call trace:
[  366.473269]  __switch_to+0xc8/0x120
[  366.476852]  __schedule+0x3d0/0x910
[  366.480442]  schedule+0x74/0x100
[  366.483763]  __pm_runtime_barrier+0x88/0x130
[  366.488148]  pm_runtime_barrier+0x5c/0xe0
[  366.492271]  device_shutdown+0xec/0x530
[  366.496217]  kernel_power_off+0x3c/0x80
[  366.500160]  __do_sys_reboot+0x154/0x230
[  366.504185]  __arm64_sys_reboot+0x2c/0x40
[  366.508306]  el0_svc_common.constprop.0+0x7c/0x1c0
[  366.513236]  do_el0_svc+0x34/0xa0
[  366.516641]  el0_svc+0x1c/0x30
[  366.519778]  el0_sync_handler+0xa8/0xb0
[  366.523715]  el0_sync+0x16c/0x180
[  366.527132] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  366.535727] Workqueue: pm pm_runtime_work
[  366.539856] Call trace:
[  366.542376]  __switch_to+0xc8/0x120
[  366.545960]  __schedule+0x3d0/0x910
[  366.549545]  schedule+0x74/0x100
[  366.552866]  schedule_timeout+0x2d4/0x330
[  366.556986]  wait_for_completion+0x88/0x110
[  366.561276]  __flush_work.isra.0+0x104/0x220
[  366.565665]  __cancel_work_timer+0x144/0x1b0
[  366.570058]  cancel_delayed_work_sync+0x24/0x30
[  366.574721]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  366.580907]  __rpm_callback+0xfc/0x1a0
[  366.584773]  rpm_callback+0x34/0xa0
[  366.588360]  rpm_suspend+0xe0/0x620
[  366.591944]  pm_runtime_work+0xbc/0xc0
[  366.595797]  process_one_work+0x1c0/0x4a0
[  366.599923]  worker_thread+0x50/0x420
[  366.603682]  kthread+0x148/0x170
[  366.607005]  ret_from_fork+0x10/0x18
[  366.610683] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  366.619278] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  366.625366] Call trace:
[  366.627884]  __switch_to+0xc8/0x120
[  366.631471]  __schedule+0x3d0/0x910
[  366.635063]  schedule+0x74/0x100
[  366.638381]  rpm_resume+0x154/0x740
[  366.641966]  __pm_runtime_resume+0x40/0x90
[  366.646177]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  366.651822]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  366.657294]  process_one_work+0x1c0/0x4a0
[  366.661421]  worker_thread+0x50/0x420
[  366.665178]  kthread+0x148/0x170
[  366.668494]  ret_from_fork+0x10/0x18
[  366.672169] INFO: task kworker/3:3:156 blocked for more than 244 seconds.
[  366.679154]       Tainted: G           OE     5.10.120-tegra #4
[  366.685253] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  366.693309] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  366.701904] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  366.708005] Call trace:
[  366.710520]  __switch_to+0xc8/0x120
[  366.714103]  __schedule+0x3d0/0x910
[  366.717688]  schedule+0x74/0x100
[  366.721002]  rpm_resume+0x154/0x740
[  366.724586]  __pm_runtime_resume+0x40/0x90
[  366.728801]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  366.734443]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  366.739908]  process_one_work+0x1c0/0x4a0
[  366.744033]  worker_thread+0x50/0x420
[  366.747797]  kthread+0x148/0x170
[  366.751113]  ret_from_fork+0x10/0x18
[  366.754784] ====DBG: Blocked tasks====<check_hung_task>
[  366.760162] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  366.768772] Call trace:
[  366.771293]  __switch_to+0xc8/0x120
[  366.774883]  __schedule+0x3d0/0x910
[  366.778468]  schedule+0x74/0x100
[  366.781785]  __pm_runtime_barrier+0x88/0x130
[  366.786169]  pm_runtime_barrier+0x5c/0xe0
[  366.790291]  device_shutdown+0xec/0x530
[  366.794236]  kernel_power_off+0x3c/0x80
[  366.798173]  __do_sys_reboot+0x154/0x230
[  366.802198]  __arm64_sys_reboot+0x2c/0x40
[  366.806329]  el0_svc_common.constprop.0+0x7c/0x1c0
[  366.811260]  do_el0_svc+0x34/0xa0
[  366.814668]  el0_svc+0x1c/0x30
[  366.817814]  el0_sync_handler+0xa8/0xb0
[  366.821752]  el0_sync+0x16c/0x180
[  366.825167] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  366.833757] Workqueue: pm pm_runtime_work
[  366.837880] Call trace:
[  366.840398]  __switch_to+0xc8/0x120
[  366.843983]  __schedule+0x3d0/0x910
[  366.847569]  schedule+0x74/0x100
[  366.850888]  schedule_timeout+0x2d4/0x330
[  366.855009]  wait_for_completion+0x88/0x110
[  366.859305]  __flush_work.isra.0+0x104/0x220
[  366.863699]  __cancel_work_timer+0x144/0x1b0
[  366.868083]  cancel_delayed_work_sync+0x24/0x30
[  366.872747]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  366.878939]  __rpm_callback+0xfc/0x1a0
[  366.882793]  rpm_callback+0x34/0xa0
[  366.886386]  rpm_suspend+0xe0/0x620
[  366.889968]  pm_runtime_work+0xbc/0xc0
[  366.893822]  process_one_work+0x1c0/0x4a0
[  366.897951]  worker_thread+0x50/0x420
[  366.901714]  kthread+0x148/0x170
[  366.905031]  ret_from_fork+0x10/0x18
[  366.908707] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  366.917309] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  366.923394] Call trace:
[  366.925915]  __switch_to+0xc8/0x120
[  366.929500]  __schedule+0x3d0/0x910
[  366.933083]  schedule+0x74/0x100
[  366.936404]  rpm_resume+0x154/0x740
[  366.939991]  __pm_runtime_resume+0x40/0x90
[  366.944207]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  366.949870]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  366.955340]  process_one_work+0x1c0/0x4a0
[  366.959465]  worker_thread+0x50/0x420
[  366.963224]  kthread+0x148/0x170
[  366.966542]  ret_from_fork+0x10/0x18
[  488.930326] INFO: task systemd-shutdow:1 blocked for more than 366 seconds.
[  488.937507]       Tainted: G           OE     5.10.120-tegra #4
[  488.943597] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  488.951648] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  488.960239] Call trace:
[  488.962772]  __switch_to+0xc8/0x120
[  488.966366]  __schedule+0x3d0/0x910
[  488.969947]  schedule+0x74/0x100
[  488.973268]  __pm_runtime_barrier+0x88/0x130
[  488.977660]  pm_runtime_barrier+0x5c/0xe0
[  488.981778]  device_shutdown+0xec/0x530
[  488.985726]  kernel_power_off+0x3c/0x80
[  488.989665]  __do_sys_reboot+0x154/0x230
[  488.993690]  __arm64_sys_reboot+0x2c/0x40
[  488.997810]  el0_svc_common.constprop.0+0x7c/0x1c0
[  489.002750]  do_el0_svc+0x34/0xa0
[  489.006154]  el0_svc+0x1c/0x30
[  489.009291]  el0_sync_handler+0xa8/0xb0
[  489.013237]  el0_sync+0x16c/0x180
[  489.016641] ====DBG: Blocked tasks====<check_hung_task>
[  489.022035] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  489.030633] Call trace:
[  489.033153]  __switch_to+0xc8/0x120
[  489.036737]  __schedule+0x3d0/0x910
[  489.040327]  schedule+0x74/0x100
[  489.043652]  __pm_runtime_barrier+0x88/0x130
[  489.048036]  pm_runtime_barrier+0x5c/0xe0
[  489.052159]  device_shutdown+0xec/0x530
[  489.056106]  kernel_power_off+0x3c/0x80
[  489.060044]  __do_sys_reboot+0x154/0x230
[  489.064071]  __arm64_sys_reboot+0x2c/0x40
[  489.068194]  el0_svc_common.constprop.0+0x7c/0x1c0
[  489.073122]  do_el0_svc+0x34/0xa0
[  489.076528]  el0_svc+0x1c/0x30
[  489.079669]  el0_sync_handler+0xa8/0xb0
[  489.083617]  el0_sync+0x16c/0x180
[  489.087056] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  489.095648] Workqueue: pm pm_runtime_work
[  489.099772] Call trace:
[  489.102288]  __switch_to+0xc8/0x120
[  489.105881]  __schedule+0x3d0/0x910
[  489.109467]  schedule+0x74/0x100
[  489.112798]  schedule_timeout+0x2d4/0x330
[  489.116923]  wait_for_completion+0x88/0x110
[  489.121222]  __flush_work.isra.0+0x104/0x220
[  489.125606]  __cancel_work_timer+0x144/0x1b0
[  489.130002]  cancel_delayed_work_sync+0x24/0x30
[  489.134675]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  489.140841]  __rpm_callback+0xfc/0x1a0
[  489.144703]  rpm_callback+0x34/0xa0
[  489.148291]  rpm_suspend+0xe0/0x620
[  489.151881]  pm_runtime_work+0xbc/0xc0
[  489.155730]  process_one_work+0x1c0/0x4a0
[  489.159863]  worker_thread+0x50/0x420
[  489.163623]  kthread+0x148/0x170
[  489.166942]  ret_from_fork+0x10/0x18
[  489.170620] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  489.179216] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  489.185304] Call trace:
[  489.187820]  __switch_to+0xc8/0x120
[  489.191408]  __schedule+0x3d0/0x910
[  489.194995]  schedule+0x74/0x100
[  489.198310]  rpm_resume+0x154/0x740
[  489.201890]  __pm_runtime_resume+0x40/0x90
[  489.206102]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  489.211745]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  489.217212]  process_one_work+0x1c0/0x4a0
[  489.221341]  worker_thread+0x50/0x420
[  489.225105]  kthread+0x148/0x170
[  489.228424]  ret_from_fork+0x10/0x18
[  489.232127] INFO: task kworker/1:8:144 blocked for more than 366 seconds.
[  489.239114]       Tainted: G           OE     5.10.120-tegra #4
[  489.245214] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  489.253269] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  489.261867] Workqueue: pm pm_runtime_work
[  489.265989] Call trace:
[  489.268506]  __switch_to+0xc8/0x120
[  489.272088]  __schedule+0x3d0/0x910
[  489.275675]  schedule+0x74/0x100
[  489.278997]  schedule_timeout+0x2d4/0x330
[  489.283112]  wait_for_completion+0x88/0x110
[  489.287410]  __flush_work.isra.0+0x104/0x220
[  489.291795]  __cancel_work_timer+0x144/0x1b0
[  489.296178]  cancel_delayed_work_sync+0x24/0x30
[  489.300851]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  489.307029]  __rpm_callback+0xfc/0x1a0
[  489.310885]  rpm_callback+0x34/0xa0
[  489.314470]  rpm_suspend+0xe0/0x620
[  489.318052]  pm_runtime_work+0xbc/0xc0
[  489.321913]  process_one_work+0x1c0/0x4a0
[  489.326041]  worker_thread+0x50/0x420
[  489.329805]  kthread+0x148/0x170
[  489.333123]  ret_from_fork+0x10/0x18
[  489.336803] ====DBG: Blocked tasks====<check_hung_task>
[  489.342180] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  489.350769] Call trace:
[  489.353285]  __switch_to+0xc8/0x120
[  489.356877]  __schedule+0x3d0/0x910
[  489.360465]  schedule+0x74/0x100
[  489.363783]  __pm_runtime_barrier+0x88/0x130
[  489.368167]  pm_runtime_barrier+0x5c/0xe0
[  489.372283]  device_shutdown+0xec/0x530
[  489.376219]  kernel_power_off+0x3c/0x80
[  489.380165]  __do_sys_reboot+0x154/0x230
[  489.384199]  __arm64_sys_reboot+0x2c/0x40
[  489.388316]  el0_svc_common.constprop.0+0x7c/0x1c0
[  489.393242]  do_el0_svc+0x34/0xa0
[  489.396646]  el0_svc+0x1c/0x30
[  489.399785]  el0_sync_handler+0xa8/0xb0
[  489.403726]  el0_sync+0x16c/0x180
[  489.407143] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  489.415738] Workqueue: pm pm_runtime_work
[  489.419862] Call trace:
[  489.422376]  __switch_to+0xc8/0x120
[  489.425956]  __schedule+0x3d0/0x910
[  489.429538]  schedule+0x74/0x100
[  489.432858]  schedule_timeout+0x2d4/0x330
[  489.436983]  wait_for_completion+0x88/0x110
[  489.441280]  __flush_work.isra.0+0x104/0x220
[  489.445672]  __cancel_work_timer+0x144/0x1b0
[  489.450061]  cancel_delayed_work_sync+0x24/0x30
[  489.454721]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  489.460898]  __rpm_callback+0xfc/0x1a0
[  489.464753]  rpm_callback+0x34/0xa0
[  489.468339]  rpm_suspend+0xe0/0x620
[  489.471928]  pm_runtime_work+0xbc/0xc0
[  489.475777]  process_one_work+0x1c0/0x4a0
[  489.479906]  worker_thread+0x50/0x420
[  489.483666]  kthread+0x148/0x170
[  489.486990]  ret_from_fork+0x10/0x18
[  489.490674] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  489.499276] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  489.505378] Call trace:
[  489.507893]  __switch_to+0xc8/0x120
[  489.511479]  __schedule+0x3d0/0x910
[  489.515066]  schedule+0x74/0x100
[  489.518384]  rpm_resume+0x154/0x740
[  489.521965]  __pm_runtime_resume+0x40/0x90
[  489.526173]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  489.531812]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  489.537278]  process_one_work+0x1c0/0x4a0
[  489.541397]  worker_thread+0x50/0x420
[  489.545153]  kthread+0x148/0x170
[  489.548473]  ret_from_fork+0x10/0x18
[  489.552159] INFO: task kworker/3:3:156 blocked for more than 367 seconds.
[  489.559150]       Tainted: G           OE     5.10.120-tegra #4
[  489.565247] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  489.573302] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  489.581896] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  489.587985] Call trace:
[  489.590506]  __switch_to+0xc8/0x120
[  489.594093]  __schedule+0x3d0/0x910
[  489.597680]  schedule+0x74/0x100
[  489.600999]  rpm_resume+0x154/0x740
[  489.604587]  __pm_runtime_resume+0x40/0x90
[  489.608807]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  489.614446]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  489.619912]  process_one_work+0x1c0/0x4a0
[  489.624035]  worker_thread+0x50/0x420
[  489.627804]  kthread+0x148/0x170
[  489.631120]  ret_from_fork+0x10/0x18
[  489.634793] ====DBG: Blocked tasks====<check_hung_task>
[  489.640162] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  489.648750] Call trace:
[  489.651271]  __switch_to+0xc8/0x120
[  489.654857]  __schedule+0x3d0/0x910
[  489.658441]  schedule+0x74/0x100
[  489.661754]  __pm_runtime_barrier+0x88/0x130
[  489.666144]  pm_runtime_barrier+0x5c/0xe0
[  489.670259]  device_shutdown+0xec/0x530
[  489.674196]  kernel_power_off+0x3c/0x80
[  489.678130]  __do_sys_reboot+0x154/0x230
[  489.682154]  __arm64_sys_reboot+0x2c/0x40
[  489.686283]  el0_svc_common.constprop.0+0x7c/0x1c0
[  489.691218]  do_el0_svc+0x34/0xa0
[  489.694625]  el0_svc+0x1c/0x30
[  489.697762]  el0_sync_handler+0xa8/0xb0
[  489.701699]  el0_sync+0x16c/0x180
[  489.705114] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  489.713713] Workqueue: pm pm_runtime_work
[  489.717837] Call trace:
[  489.720353]  __switch_to+0xc8/0x120
[  489.723944]  __schedule+0x3d0/0x910
[  489.727528]  schedule+0x74/0x100
[  489.730851]  schedule_timeout+0x2d4/0x330
[  489.734969]  wait_for_completion+0x88/0x110
[  489.739270]  __flush_work.isra.0+0x104/0x220
[  489.743658]  __cancel_work_timer+0x144/0x1b0
[  489.748051]  cancel_delayed_work_sync+0x24/0x30
[  489.752717]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  489.758890]  __rpm_callback+0xfc/0x1a0
[  489.762741]  rpm_callback+0x34/0xa0
[  489.766326]  rpm_suspend+0xe0/0x620
[  489.769917]  pm_runtime_work+0xbc/0xc0
[  489.773765]  process_one_work+0x1c0/0x4a0
[  489.777892]  worker_thread+0x50/0x420
[  489.781652]  kthread+0x148/0x170
[  489.784972]  ret_from_fork+0x10/0x18
[  489.788643] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  489.797244] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  489.803334] Call trace:
[  489.805847]  __switch_to+0xc8/0x120
[  489.809431]  __schedule+0x3d0/0x910
[  489.813017]  schedule+0x74/0x100
[  489.816344]  rpm_resume+0x154/0x740
[  489.819934]  __pm_runtime_resume+0x40/0x90
[  489.824141]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  489.829788]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  489.835252]  process_one_work+0x1c0/0x4a0
[  489.839373]  worker_thread+0x50/0x420
[  489.843140]  kthread+0x148/0x170
[  489.846456]  ret_from_fork+0x10/0x18
[  611.810325] INFO: task systemd-shutdow:1 blocked for more than 489 seconds.
[  611.817500]       Tainted: G           OE     5.10.120-tegra #4
[  611.823604] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  611.831663] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  611.840257] Call trace:
[  611.842785]  __switch_to+0xc8/0x120
[  611.846376]  __schedule+0x3d0/0x910
[  611.849968]  schedule+0x74/0x100
[  611.853291]  __pm_runtime_barrier+0x88/0x130
[  611.857675]  pm_runtime_barrier+0x5c/0xe0
[  611.861800]  device_shutdown+0xec/0x530
[  611.865742]  kernel_power_off+0x3c/0x80
[  611.869681]  __do_sys_reboot+0x154/0x230
[  611.873705]  __arm64_sys_reboot+0x2c/0x40
[  611.877827]  el0_svc_common.constprop.0+0x7c/0x1c0
[  611.882754]  do_el0_svc+0x34/0xa0
[  611.886169]  el0_svc+0x1c/0x30
[  611.889305]  el0_sync_handler+0xa8/0xb0
[  611.893253]  el0_sync+0x16c/0x180
[  611.896656] ====DBG: Blocked tasks====<check_hung_task>
[  611.902035] task:systemd-shutdow state:D stack:    0 pid:    1 ppid:     0 flags:0x00000008
[  611.910648] Call trace:
[  611.913168]  __switch_to+0xc8/0x120
[  611.916754]  __schedule+0x3d0/0x910
[  611.920339]  schedule+0x74/0x100
[  611.923657]  __pm_runtime_barrier+0x88/0x130
[  611.928051]  pm_runtime_barrier+0x5c/0xe0
[  611.932174]  device_shutdown+0xec/0x530
[  611.936117]  kernel_power_off+0x3c/0x80
[  611.940060]  __do_sys_reboot+0x154/0x230
[  611.944089]  __arm64_sys_reboot+0x2c/0x40
[  611.948217]  el0_svc_common.constprop.0+0x7c/0x1c0
[  611.953150]  do_el0_svc+0x34/0xa0
[  611.956556]  el0_svc+0x1c/0x30
[  611.959696]  el0_sync_handler+0xa8/0xb0
[  611.963637]  el0_sync+0x16c/0x180
[  611.967075] task:kworker/1:8     state:D stack:    0 pid:  144 ppid:     2 flags:0x00000028
[  611.975665] Workqueue: pm pm_runtime_work
[  611.979790] Call trace:
[  611.982304]  __switch_to+0xc8/0x120
[  611.985888]  __schedule+0x3d0/0x910
[  611.989472]  schedule+0x74/0x100
[  611.992804]  schedule_timeout+0x2d4/0x330
[  611.996928]  wait_for_completion+0x88/0x110
[  612.001234]  __flush_work.isra.0+0x104/0x220
[  612.005624]  __cancel_work_timer+0x144/0x1b0
[  612.010014]  cancel_delayed_work_sync+0x24/0x30
[  612.014688]  hda_codec_runtime_suspend+0x2c/0xe0 [snd_hda_codec]
[  612.020855]  __rpm_callback+0xfc/0x1a0
[  612.024719]  rpm_callback+0x34/0xa0
[  612.028304]  rpm_suspend+0xe0/0x620
[  612.031894]  pm_runtime_work+0xbc/0xc0
[  612.035755]  process_one_work+0x1c0/0x4a0
[  612.039883]  worker_thread+0x50/0x420
[  612.043642]  kthread+0x148/0x170
[  612.046968]  ret_from_fork+0x10/0x18
[  612.050647] task:kworker/3:3     state:D stack:    0 pid:  156 ppid:     2 flags:0x00000028
[  612.059247] Workqueue: events hda_jackpoll_work [snd_hda_codec]
[  612.065329] Call trace:
[  612.067844]  __switch_to+0xc8/0x120
[  612.071432]  __schedule+0x3d0/0x910
[  612.075025]  schedule+0x74/0x100
[  612.078343]  rpm_resume+0x154/0x740
[  612.081936]  __pm_runtime_resume+0x40/0x90
[  612.086155]  snd_hdac_power_up_pm+0x78/0x90 [snd_hda_core]
[  612.091806]  hda_jackpoll_work+0x50/0xa0 [snd_hda_codec]
[  612.097272]  process_one_work+0x1c0/0x4a0
[  612.101392]  worker_thread+0x50/0x420
[  612.105156]  kthread+0x148/0x170
[  612.108478]  ret_from_fork+0x10/0x18

OrinNanoDBG_hda_codec.txt (829.8 KB)

Hi Wilson,
Can you apply the attached
patch.txt (3.3 KB)
in your tree and get the fresh log when the issue reproduced again.

This will help to understand the root cause and to provide fix.

This is the test result.
OrinNanoDBG_hda_codec_patch2.txt (847.7 KB)

I hope the above patch is included in your build.

From the log, seems like codec shutdown callback completed before jackpoll worker thread cleaned up.

[ 19.951304] snd_hda_codec_hdmi hdaudioC0D0: hda_jackpoll_work 648
[ 19.955305] snd_hda_codec_hdmi hdaudioC0D0: hda_codec_runtime_suspend 2955

Can you add debug print in the function snd_hda_codec_shutdown() in hda_bind.c. Just like to understand why its not cleaned as we have cancel_delayed_work_sync(&codec->jackpoll_work); in this function.

Hi mkumard,

I have added 0001 patch in last test. (add 0001 and patch.txt both)
Can you give me the code what debug print you want?
I just know to add some log like this :

[   80.937008] ====Wilson add: DBG: Blocked tasks====<hda_codec_driver_shutdown>
[   80.944404] ====Wilson add: DBG: Blocked tasks====<snd_hda_codec_shutdown>

Hi Wilson,
Just add codec_err(codec, “%s %d\n”,__func __,__LINE __); at start and end of the function snd_hda_codec_shutdown()

I suspect some corner case in not cleaning up jack poll worker thread. Let’s get this log to understand the flow.