Messages in this thread |  | | From | Andy Shevchenko <> | Date | Sun, 9 May 2021 12:42:08 +0300 | Subject | Re: [PATCH][v2] rtnetlink: add rtnl_lock debug log |
| |
On Sat, May 8, 2021 at 12:11 PM Rocco Yue <rocco.yue@mediatek.com> wrote: > > We often encounter system hangs caused by certain process > holding rtnl_lock for a long time. Even if there is a lock > detection mechanism in Linux, it is a bit troublesome and > affects the system performance. We hope to add a lightweight > debugging mechanism for detecting rtnl_lock. > > Up to now, we have discovered and solved some potential bugs > through this lightweight rtnl_lock debugging mechanism, which > is helpful for us. > > When you say Y for RTNL_LOCK_DEBUG, then the kernel will detect > if any function hold rtnl_lock too long and some key information > will be printed out to help locate the problem. > > i.e: from the following logs, we can clearly know that the pid=2206 > RfxSender_4 process holds rtnl_lock for a long time, causing the > system to hang. And we can also speculate that the delay operation > may be performed in devinet_ioctl(), resulting in rtnl_lock was > not released in time. > > <6>[ 40.191481][ C6] rtnetlink: -- rtnl_print_btrace start --
You don't seem to get it. It's a quite long trace for the commit message. Do you need all those lines below? Why?
> <6>[ 40.191494][ C6] rtnetlink: RfxSender_4[2206][R] hold rtnl_lock > more than 2 sec, start time: 38181400013 > <4>[ 40.191510][ C6] devinet_ioctl+0x1fc/0x75c > <4>[ 40.191517][ C6] inet_ioctl+0xb8/0x1f8 > <4>[ 40.191527][ C6] sock_do_ioctl+0x70/0x2ac > <4>[ 40.191533][ C6] sock_ioctl+0x5dc/0xa74 > <4>[ 40.191541][ C6] __arm64_sys_ioctl+0x178/0x1fc > <4>[ 40.191548][ C6] el0_svc_common+0xc0/0x24c > <4>[ 40.191555][ C6] el0_svc+0x28/0x88 > <4>[ 40.191560][ C6] el0_sync_handler+0x8c/0xf0 > <4>[ 40.191566][ C6] el0_sync+0x198/0x1c0 > <6>[ 40.191571][ C6] Call trace: > <6>[ 40.191586][ C6] rtnl_print_btrace+0xf0/0x124 > <6>[ 40.191595][ C6] call_timer_fn+0x5c/0x3b4 > <6>[ 40.191602][ C6] expire_timers+0xe0/0x49c > <6>[ 40.191609][ C6] __run_timers+0x34c/0x48c > <6>[ 40.191616][ C6] run_timer_softirq+0x28/0x58 > <6>[ 40.191621][ C6] efi_header_end+0x168/0x690 > <6>[ 40.191628][ C6] __irq_exit_rcu+0x108/0x124 > <6>[ 40.191635][ C6] __handle_domain_irq+0x130/0x1b4 > <6>[ 40.191643][ C6] gic_handle_irq.29882+0x6c/0x2d8 > <6>[ 40.191648][ C6] el1_irq+0xdc/0x1c0 > <6>[ 40.191656][ C6] __delay+0xc0/0x180 > <6>[ 40.191663][ C6] devinet_ioctl+0x21c/0x75c > <6>[ 40.191668][ C6] inet_ioctl+0xb8/0x1f8 > <6>[ 40.191675][ C6] sock_do_ioctl+0x70/0x2ac > <6>[ 40.191682][ C6] sock_ioctl+0x5dc/0xa74 > <6>[ 40.191688][ C6] __arm64_sys_ioctl+0x178/0x1fc > <6>[ 40.191694][ C6] el0_svc_common+0xc0/0x24c > <6>[ 40.191699][ C6] el0_svc+0x28/0x88 > <6>[ 40.191705][ C6] el0_sync_handler+0x8c/0xf0 > <6>[ 40.191710][ C6] el0_sync+0x198/0x1c0 > <6>[ 40.191715][ C6] rtnetlink: -- rtnl_print_btrace end -- > > <6>[ 42.181879][ T2206] rtnetlink: rtnl_lock is held by [2206] from > [38181400013] to [42181875177]
-- With Best Regards, Andy Shevchenko
|  |