| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Date: Mon, 10 May 2021 15:19:26 +0300
From: Andy Shevchenko <andy.shevchenko@...il.com>
To: "Rocco.Yue" <rocco.yue@...iatek.com>
Cc: "David S . Miller" <davem@...emloft.net>,
Jakub Kicinski <kuba@...nel.org>,
Matthias Brugger <matthias.bgg@...il.com>,
Andrew Morton <akpm@...ux-foundation.org>,
Masahiro Yamada <masahiroy@...nel.org>,
Nick Desaulniers <ndesaulniers@...gle.com>,
"Peter Zijlstra (Intel)" <peterz@...radead.org>,
Tetsuo Handa <penguin-kernel@...ove.sakura.ne.jp>,
Peter Enderborg <peter.enderborg@...y.com>,
Thomas Gleixner <tglx@...utronix.de>,
Anshuman Khandual <anshuman.khandual@....com>,
Vitor Massaru Iha <vitor@...saru.org>,
Sedat Dilek <sedat.dilek@...il.com>,
Wei Yang <richard.weiyang@...il.com>,
Cong Wang <cong.wang@...edance.com>,
Di Zhu <zhudi21@...wei.com>,
Stephen Hemminger <stephen@...workplumber.org>,
Francis Laniel <laniel_francis@...vacyrequired.com>,
Roopa Prabhu <roopa@...ulusnetworks.com>,
Andrii Nakryiko <andrii@...nel.org>,
Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
netdev <netdev@...r.kernel.org>,
linux-arm Mailing List <linux-arm-kernel@...ts.infradead.org>,
"moderated list:ARM/Mediatek SoC support"
<linux-mediatek@...ts.infradead.org>, wsd_upsream@...iatek.com
Subject: Re: [PATCH][v2] rtnetlink: add rtnl_lock debug log
On Mon, May 10, 2021 at 03:23:41PM +0800, Rocco.Yue wrote:
> On Sun, 2021-05-09 at 12:42 +0300, Andy Shevchenko wrote:
> > On Sat, May 8, 2021 at 12:11 PM Rocco Yue <rocco.yue@...iatek.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?
> >
>
> The contents shown in all the lines below are the original printed after
> adding this patch, I pasted these lines into commit message to
> illustrate this patch as a case.
>
> It now appears that some of following are indeed unnecessary, I am going
> to condense a lot of following contents as follows.
>
> Could you please help to take a look at it again? many thanks :-)
>
> [ 40.191481] rtnetlink: -- rtnl_print_btrace start --
> [ 40.191494] RfxSender_4[2206][R] hold rtnl_lock more than 2 sec,
> start time: 38181400013
> [ 40.191571] Call trace:
> [ 40.191586] rtnl_print_btrace+0xf0/0x124
> [ 40.191656] __delay+0xc0/0x180
> [ 40.191663] devinet_ioctl+0x21c/0x75c
> [ 40.191668] inet_ioctl+0xb8/0x1f8
> [ 40.191675] sock_do_ioctl+0x70/0x2ac
> [ 40.191682] sock_ioctl+0x5dc/0xa74
> [ 40.191715] rtnetlink: -- rtnl_print_btrace end --
> [ 42.181879] rtnetlink: rtnl_lock is held by [2206] from
> [38181400013] to [42181875177]
Much better, thanks!
(You still need a real review on the contents of the change)
> > > <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
Powered by blists - more mailing lists