search

JeffyCN / meta-rockchip

Yocto BSP layer for the Rockchip SOC boards
Other
114 stars 87 forks source link

RK3399 Rockchip kernel 4.19, non fatal USB hang at startup #22

Closed DiegoDassie closed 2 years ago

DiegoDassie commented 2 years ago

Goodmorning Jeffy,

I have been running the rockchip kernel 4.19 _(kernel-4.19-2022_0118) on my Yocto for a custom RK3399 board and noticed that sometimes at startup a non fatal kernel hang is reported from the USB subsystem, because I'm not able to easily reproduce the hang I decided to investigate and enabled the kernel lock debugging I think I found a possible deadlock that seems to be related to the USB hang I am getting, here is the relevant kernel log:

Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013082]  [5:    kworker/5:3:   78] BUG: workqueue leaked lock or atomic: kworker/5:3/0x00000000/78
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013082]  [5:    kworker/5:3:   78]      last function: rockchip_chg_detect_work
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013241]  [5:    kworker/5:3:   78] 1 lock held by kworker/5:3/78:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013249]  [5:    kworker/5:3:   78]  #0: 0000000035a79ffd (&rport->mutex){+.+.}, at: rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013272]  [5:    kworker/5:3:   78] CPU: 5 PID: 78 Comm: kworker/5:3 Not tainted 4.19.219-<redacted> #1
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013280]  [5:    kworker/5:3:   78] Hardware name: <redacted> (DT)
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013292]  [5:    kworker/5:3:   78] Workqueue: events rockchip_chg_detect_work
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013301]  [5:    kworker/5:3:   78] Call trace:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013312]  [5:    kworker/5:3:   78]  dump_backtrace+0x0/0x170
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013321]  [5:    kworker/5:3:   78]  show_stack+0x28/0x34
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013330]  [5:    kworker/5:3:   78]  dump_stack+0xb4/0xec
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013339]  [5:    kworker/5:3:   78]  process_one_work+0x520/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013347]  [5:    kworker/5:3:   78]  worker_thread+0x6c/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013355]  [5:    kworker/5:3:   78]  kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013362]  [5:    kworker/5:3:   78]  ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013543]  [5:    kworker/5:3:   78] BUG: workqueue leaked lock or atomic: kworker/5:3/0x00000000/78
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013543]  [5:    kworker/5:3:   78]      last function: pm_runtime_work
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013565]  [5:    kworker/5:3:   78] 1 lock held by kworker/5:3/78:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013573]  [5:    kworker/5:3:   78]  #0: 0000000035a79ffd (&rport->mutex){+.+.}, at: rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013590]  [5:    kworker/5:3:   78] CPU: 5 PID: 78 Comm: kworker/5:3 Not tainted 4.19.219-<redacted> #1
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013597]  [5:    kworker/5:3:   78] Hardware name: <redacted> (DT)
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013608]  [5:    kworker/5:3:   78] Workqueue: pm pm_runtime_work
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013616]  [5:    kworker/5:3:   78] Call trace:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013624]  [5:    kworker/5:3:   78]  dump_backtrace+0x0/0x170
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013633]  [5:    kworker/5:3:   78]  show_stack+0x28/0x34
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013640]  [5:    kworker/5:3:   78]  dump_stack+0xb4/0xec
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013648]  [5:    kworker/5:3:   78]  process_one_work+0x520/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013656]  [5:    kworker/5:3:   78]  worker_thread+0x6c/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013664]  [5:    kworker/5:3:   78]  kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.013671]  [5:    kworker/5:3:   78]  ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.090914]  [5:    kworker/5:3:   78] BUG: workqueue leaked lock or atomic: kworker/5:3/0x00000000/78
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.090914]  [5:    kworker/5:3:   78]      last function: drain_local_pages_wq
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.090943]  [5:    kworker/5:3:   78] 1 lock held by kworker/5:3/78:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.090951]  [5:    kworker/5:3:   78]  #0: 0000000035a79ffd (&rport->mutex){+.+.}, at: rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.090975]  [5:    kworker/5:3:   78] CPU: 5 PID: 78 Comm: kworker/5:3 Not tainted 4.19.219-<redacted> #1
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.090983]  [5:    kworker/5:3:   78] Hardware name: <redacted> (DT)
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.090996]  [5:    kworker/5:3:   78] Workqueue: mm_percpu_wq drain_local_pages_wq
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091004]  [5:    kworker/5:3:   78] Call trace:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091015]  [5:    kworker/5:3:   78]  dump_backtrace+0x0/0x170
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091024]  [5:    kworker/5:3:   78]  show_stack+0x28/0x34
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091032]  [5:    kworker/5:3:   78]  dump_stack+0xb4/0xec
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091042]  [5:    kworker/5:3:   78]  process_one_work+0x520/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091050]  [5:    kworker/5:3:   78]  worker_thread+0x234/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091058]  [5:    kworker/5:3:   78]  kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091066]  [5:    kworker/5:3:   78]  ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091211]  [5:    kworker/5:3:   78] BUG: workqueue leaked lock or atomic: kworker/5:3/0x00000000/78
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091211]  [5:    kworker/5:3:   78]      last function: wq_barrier_func
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091231]  [5:    kworker/5:3:   78] 1 lock held by kworker/5:3/78:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091239]  [5:    kworker/5:3:   78]  #0: 0000000035a79ffd (&rport->mutex){+.+.}, at: rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091257]  [5:    kworker/5:3:   78] CPU: 5 PID: 78 Comm: kworker/5:3 Not tainted 4.19.219-<redacted> #1
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091264]  [5:    kworker/5:3:   78] Hardware name: <redacted> (DT)
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091275]  [5:    kworker/5:3:   78] Workqueue: mm_percpu_wq wq_barrier_func
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091282]  [5:    kworker/5:3:   78] Call trace:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091291]  [5:    kworker/5:3:   78]  dump_backtrace+0x0/0x170
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091299]  [5:    kworker/5:3:   78]  show_stack+0x28/0x34
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091307]  [5:    kworker/5:3:   78]  dump_stack+0xb4/0xec
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091315]  [5:    kworker/5:3:   78]  process_one_work+0x520/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091323]  [5:    kworker/5:3:   78]  worker_thread+0x234/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091330]  [5:    kworker/5:3:   78]  kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.091338]  [5:    kworker/5:3:   78]  ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092169]  [5:    kworker/5:3:   78] BUG: workqueue leaked lock or atomic: kworker/5:3/0x00000000/78
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092169]  [5:    kworker/5:3:   78]      last function: drain_local_pages_wq
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092191]  [5:    kworker/5:3:   78] 1 lock held by kworker/5:3/78:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092199]  [5:    kworker/5:3:   78]  #0: 0000000035a79ffd (&rport->mutex){+.+.}, at: rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092265]  [5:    kworker/5:3:   78] CPU: 5 PID: 78 Comm: kworker/5:3 Not tainted 4.19.219-<redacted> #1
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092272]  [5:    kworker/5:3:   78] Hardware name: <redacted> (DT)
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092283]  [5:    kworker/5:3:   78] Workqueue: mm_percpu_wq drain_local_pages_wq
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092291]  [5:    kworker/5:3:   78] Call trace:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092300]  [5:    kworker/5:3:   78]  dump_backtrace+0x0/0x170
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092308]  [5:    kworker/5:3:   78]  show_stack+0x28/0x34
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092316]  [5:    kworker/5:3:   78]  dump_stack+0xb4/0xec
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092325]  [5:    kworker/5:3:   78]  process_one_work+0x520/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092333]  [5:    kworker/5:3:   78]  worker_thread+0x234/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092340]  [5:    kworker/5:3:   78]  kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092348]  [5:    kworker/5:3:   78]  ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092403]  [5:    kworker/5:3:   78] BUG: workqueue leaked lock or atomic: kworker/5:3/0x00000000/78
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092403]  [5:    kworker/5:3:   78]      last function: wq_barrier_func
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092422]  [5:    kworker/5:3:   78] 1 lock held by kworker/5:3/78:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092430]  [5:    kworker/5:3:   78]  #0: 0000000035a79ffd (&rport->mutex){+.+.}, at: rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092448]  [5:    kworker/5:3:   78] CPU: 5 PID: 78 Comm: kworker/5:3 Not tainted 4.19.219-<redacted> #1
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092455]  [5:    kworker/5:3:   78] Hardware name: <redacted> (DT)
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092465]  [5:    kworker/5:3:   78] Workqueue: mm_percpu_wq wq_barrier_func
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092473]  [5:    kworker/5:3:   78] Call trace:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092481]  [5:    kworker/5:3:   78]  dump_backtrace+0x0/0x170
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092490]  [5:    kworker/5:3:   78]  show_stack+0x28/0x34
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092497]  [5:    kworker/5:3:   78]  dump_stack+0xb4/0xec
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092505]  [5:    kworker/5:3:   78]  process_one_work+0x520/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092513]  [5:    kworker/5:3:   78]  worker_thread+0x234/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092520]  [5:    kworker/5:3:   78]  kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.092528]  [5:    kworker/5:3:   78]  ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109257]  [5:    kworker/5:3:   78] BUG: workqueue leaked lock or atomic: kworker/5:3/0x00000000/78
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109257]  [5:    kworker/5:3:   78]      last function: hub_event
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109270]  [5:    kworker/5:3:   78] 1 lock held by kworker/5:3/78:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109279]  [5:    kworker/5:3:   78]  #0: 0000000035a79ffd (&rport->mutex){+.+.}, at: rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109299]  [5:    kworker/5:3:   78] CPU: 5 PID: 78 Comm: kworker/5:3 Not tainted 4.19.219-<redacted> #1
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109306]  [5:    kworker/5:3:   78] Hardware name: <redacted> (DT)
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109318]  [5:    kworker/5:3:   78] Workqueue: usb_hub_wq hub_event
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109326]  [5:    kworker/5:3:   78] Call trace:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109335]  [5:    kworker/5:3:   78]  dump_backtrace+0x0/0x170
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109343]  [5:    kworker/5:3:   78]  show_stack+0x28/0x34
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109351]  [5:    kworker/5:3:   78]  dump_stack+0xb4/0xec
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109360]  [5:    kworker/5:3:   78]  process_one_work+0x520/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109367]  [5:    kworker/5:3:   78]  worker_thread+0x6c/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109375]  [5:    kworker/5:3:   78]  kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.109383]  [5:    kworker/5:3:   78]  ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110166]  [5:    kworker/5:3:   78] BUG: workqueue leaked lock or atomic: kworker/5:3/0x00000000/78
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110166]  [5:    kworker/5:3:   78]      last function: pm_runtime_work
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110186]  [5:    kworker/5:3:   78] 1 lock held by kworker/5:3/78:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110195]  [5:    kworker/5:3:   78]  #0: 0000000035a79ffd (&rport->mutex){+.+.}, at: rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110213]  [5:    kworker/5:3:   78] CPU: 5 PID: 78 Comm: kworker/5:3 Not tainted 4.19.219-<redacted> #1
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110220]  [5:    kworker/5:3:   78] Hardware name: <redacted> (DT)
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110231]  [5:    kworker/5:3:   78] Workqueue: pm pm_runtime_work
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110239]  [5:    kworker/5:3:   78] Call trace:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110247]  [5:    kworker/5:3:   78]  dump_backtrace+0x0/0x170
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110256]  [5:    kworker/5:3:   78]  show_stack+0x28/0x34
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110263]  [5:    kworker/5:3:   78]  dump_stack+0xb4/0xec
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110272]  [5:    kworker/5:3:   78]  process_one_work+0x520/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110279]  [5:    kworker/5:3:   78]  worker_thread+0x6c/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110287]  [5:    kworker/5:3:   78]  kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.110295]  [5:    kworker/5:3:   78]  ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115836]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115847]  [5:    kworker/5:3:   78] ======================================================
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115851]  [5:    kworker/5:3:   78] WARNING: possible circular locking dependency detected
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115856]  [5:    kworker/5:3:   78] 4.19.219-<redacted> #1 Not tainted
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115859]  [5:    kworker/5:3:   78] ------------------------------------------------------
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115863]  [5:    kworker/5:3:   78] kworker/5:3/78 is trying to acquire lock:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115868]  [5:    kworker/5:3:   78] 0000000006a0005d ((wq_completion)"events"){+.+.}, at: process_one_work+0x1e0/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115878]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115878]  [5:    kworker/5:3:   78] but task is already holding lock:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115882]  [5:    kworker/5:3:   78] 0000000035a79ffd (&rport->mutex){+.+.}, at: rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115891]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115891]  [5:    kworker/5:3:   78] which lock already depends on the new lock.
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115891]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115896]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115896]  [5:    kworker/5:3:   78] the existing dependency chain (in reverse order) is:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115901]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115901]  [5:    kworker/5:3:   78] -> #2 (&rport->mutex){+.+.}:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115910]  [5:    kworker/5:3:   78]        __mutex_lock+0x7c/0x740
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115915]  [5:    kworker/5:3:   78]        mutex_lock_nested+0x48/0x5c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115921]  [5:    kworker/5:3:   78]        rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115926]  [5:    kworker/5:3:   78]        process_one_work+0x28c/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115931]  [5:    kworker/5:3:   78]        worker_thread+0x6c/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115935]  [5:    kworker/5:3:   78]        kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115940]  [5:    kworker/5:3:   78]        ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115944]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115944]  [5:    kworker/5:3:   78] -> #1 ((work_completion)(&(&rport->chg_work)->work)){+.+.}:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115953]  [5:    kworker/5:3:   78]        process_one_work+0x240/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115957]  [5:    kworker/5:3:   78]        worker_thread+0x6c/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115962]  [5:    kworker/5:3:   78]        kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115966]  [5:    kworker/5:3:   78]        ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115970]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115970]  [5:    kworker/5:3:   78] -> #0 ((wq_completion)"events"){+.+.}:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115978]  [5:    kworker/5:3:   78]        lock_acquire+0xc8/0x1d0
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115983]  [5:    kworker/5:3:   78]        process_one_work+0x21c/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115988]  [5:    kworker/5:3:   78]        worker_thread+0x6c/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115992]  [5:    kworker/5:3:   78]        kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.115996]  [5:    kworker/5:3:   78]        ret_from_fork+0x10/0x18
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116000]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116000]  [5:    kworker/5:3:   78] other info that might help us debug this:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116000]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116006]  [5:    kworker/5:3:   78] Chain exists of:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116006]  [5:    kworker/5:3:   78]   (wq_completion)"events" --> (work_completion)(&(&rport->chg_work)->work) --> &rport->mutex
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116006]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116015]  [5:    kworker/5:3:   78]  Possible unsafe locking scenario:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116015]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116020]  [5:    kworker/5:3:   78]        CPU0                    CPU1
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116024]  [5:    kworker/5:3:   78]        ----                    ----
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116027]  [5:    kworker/5:3:   78]   lock(&rport->mutex);
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116031]  [5:    kworker/5:3:   78]                                lock((work_completion)(&(&rport->chg_work)->work));
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116036]  [5:    kworker/5:3:   78]                                lock(&rport->mutex);
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116040]  [5:    kworker/5:3:   78]   lock((wq_completion)"events");
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116045]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116045]  [5:    kworker/5:3:   78]  *** DEADLOCK ***
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116045]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116051]  [5:    kworker/5:3:   78] 1 lock held by kworker/5:3/78:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116054]  [5:    kworker/5:3:   78]  #0: 0000000035a79ffd (&rport->mutex){+.+.}, at: rockchip_chg_detect_work+0x1c4/0x48c
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116062]  [5:    kworker/5:3:   78]
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116062]  [5:    kworker/5:3:   78] stack backtrace:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116068]  [5:    kworker/5:3:   78] CPU: 5 PID: 78 Comm: kworker/5:3 Not tainted 4.19.219-<redacted> #1
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116072]  [5:    kworker/5:3:   78] Hardware name: <redacted> (DT)
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116080]  [5:    kworker/5:3:   78] Workqueue: events rockchip_chg_detect_work
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116085]  [5:    kworker/5:3:   78] Call trace:
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116091]  [5:    kworker/5:3:   78]  dump_backtrace+0x0/0x170
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116096]  [5:    kworker/5:3:   78]  show_stack+0x28/0x34
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116100]  [5:    kworker/5:3:   78]  dump_stack+0xb4/0xec
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116104]  [5:    kworker/5:3:   78]  print_circular_bug.constprop.0+0x270/0x2e0
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116108]  [5:    kworker/5:3:   78]  __lock_acquire+0x1464/0x16f0
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116112]  [5:    kworker/5:3:   78]  lock_acquire+0xc8/0x1d0
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116118]  [5:    kworker/5:3:   78]  process_one_work+0x21c/0x5e4
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116122]  [5:    kworker/5:3:   78]  worker_thread+0x6c/0x440
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116126]  [5:    kworker/5:3:   78]  kthread+0x104/0x130
Apr 28 17:42:26 XX0XX000000 kernel[221]: [    1.116131]  [5:    kworker/5:3:   78]  ret_from_fork+0x10/0x18

Do you think you could take a look at it?

Thanks.

JeffyCN commented 2 years ago

sorry, don't know much about that, i mostly focus on the user space, not the kernel side.

from a quick check about the log and related code, it looks like a mutex(rport->mutex) been held after exited the charger detect work, which might be expected(not a good practice though), since it seems like a state machine, and would unlock it somewhere else.

so it might or might not related to your hang. for a hang, normally people might need to check with fiq/watchdog/jtag