* [PATCH][v2] rtnetlink: add rtnl_lock debug log
@ 2021-05-08 8:57 ` Rocco Yue
0 siblings, 0 replies; 16+ messages in thread
From: Rocco Yue @ 2021-05-08 8:57 UTC (permalink / raw)
To: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, peterz
Cc: Tetsuo Handa, Peter Enderborg, Thomas Gleixner,
Anshuman Khandual, Vitor Massaru Iha, Sedat Dilek, Wei Yang,
Cong Wang, Di Zhu, Stephen Hemminger, Francis Laniel,
Roopa Prabhu, Andrii Nakryiko, linux-kernel, netdev,
linux-arm-kernel, linux-mediatek, wsd_upsream, Rocco Yue
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 --
<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]
Signed-off-by: Rocco Yue <rocco.yue@mediatek.com>
---
lib/Kconfig.debug | 10 ++++++
net/core/rtnetlink.c | 85 ++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 95 insertions(+)
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 678c13967580..f1a722e16bee 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -2027,6 +2027,16 @@ config KCOV_IRQ_AREA_SIZE
soft interrupts. This specifies the size of those areas in the
number of unsigned long words.
+config RTNL_LOCK_DEBUG
+ bool "rtnl_lock debugging, deadlock detection"
+ depends on STACKTRACE_SUPPORT
+ select STACKTRACE
+ help
+ If you say Y here then the kernel will detect whether any function
+ hold rtnl_lock too long and some key information will be printed
+ out to help locate the problem.
+ If unsure, say N.
+
menuconfig RUNTIME_TESTING_MENU
bool "Runtime Testing"
def_bool y
diff --git a/net/core/rtnetlink.c b/net/core/rtnetlink.c
index 714d5fa38546..4f81086e5a42 100644
--- a/net/core/rtnetlink.c
+++ b/net/core/rtnetlink.c
@@ -12,6 +12,8 @@
* Vitaly E. Lavrov RTA_OK arithmetics was wrong.
*/
+#define pr_fmt(fmt) "rtnetlink: " fmt
+
#include <linux/bitops.h>
#include <linux/errno.h>
#include <linux/module.h>
@@ -57,6 +59,81 @@
#define RTNL_MAX_TYPE 50
#define RTNL_SLAVE_MAX_TYPE 40
+#ifdef CONFIG_RTNL_LOCK_DEBUG
+
+#include <linux/sched/debug.h>
+#include <linux/stacktrace.h>
+
+/* Debug log and btrace will be printed when the rtnl_lock
+ * is held for more than RTNL_LOCK_MAX_HOLD_TIME seconds
+ */
+#define RTNL_LOCK_MAX_HOLD_TIME 2
+
+#define RTNL_LOCK_MAX_TRACE 10 /* stack trace length */
+
+struct rtnl_debug_btrace_t {
+ struct task_struct *task;
+ int pid;
+ unsigned long long start_time;
+ unsigned long long end_time;
+ unsigned long addrs[RTNL_LOCK_MAX_TRACE];
+ unsigned int nr_entries;
+};
+
+static struct rtnl_debug_btrace_t rtnl_instance;
+
+static void rtnl_print_btrace(struct timer_list *unused);
+static DEFINE_TIMER(rtnl_chk_timer, rtnl_print_btrace);
+
+/* Save stack trace to the given array of RTNL_LOCK_MAX_TRACE size.
+ */
+static int __save_stack_trace(unsigned long *trace)
+{
+ return stack_trace_save(trace, RTNL_LOCK_MAX_TRACE, 0);
+}
+
+static void rtnl_get_btrace(struct task_struct *who)
+{
+ unsigned long expires;
+
+ rtnl_instance.task = who;
+ rtnl_instance.pid = who->pid;
+ rtnl_instance.start_time = sched_clock();
+ rtnl_instance.end_time = 0;
+ rtnl_instance.nr_entries = __save_stack_trace(rtnl_instance.addrs);
+
+ expires = jiffies + RTNL_LOCK_MAX_HOLD_TIME * HZ;
+ mod_timer(&rtnl_chk_timer, expires);
+}
+
+static void rtnl_print_btrace(struct timer_list *unused)
+{
+ pr_info("-- %s start --\n", __func__);
+ pr_info("%s[%d][%c] hold rtnl_lock more than %d sec, start time: %llu\n",
+ rtnl_instance.task->comm,
+ rtnl_instance.pid,
+ task_state_to_char(rtnl_instance.task),
+ RTNL_LOCK_MAX_HOLD_TIME,
+ rtnl_instance.start_time);
+ stack_trace_print(rtnl_instance.addrs, rtnl_instance.nr_entries, 0);
+ show_stack(rtnl_instance.task, NULL, KERN_INFO);
+ pr_info("-- %s end --\n", __func__);
+}
+
+static void rtnl_relase_btrace(void)
+{
+ rtnl_instance.end_time = sched_clock();
+ del_timer_sync(&rtnl_chk_timer);
+
+ if (rtnl_instance.end_time - rtnl_instance.start_time > 2 * NSEC_PER_SEC) {
+ pr_info("rtnl_lock is held by [%d] from [%llu] to [%llu]\n",
+ rtnl_instance.pid,
+ rtnl_instance.start_time,
+ rtnl_instance.end_time);
+ }
+}
+#endif
+
struct rtnl_link {
rtnl_doit_func doit;
rtnl_dumpit_func dumpit;
@@ -70,6 +147,10 @@ static DEFINE_MUTEX(rtnl_mutex);
void rtnl_lock(void)
{
mutex_lock(&rtnl_mutex);
+
+#ifdef CONFIG_RTNL_LOCK_DEBUG
+ rtnl_get_btrace(current);
+#endif
}
EXPORT_SYMBOL(rtnl_lock);
@@ -95,6 +176,10 @@ void __rtnl_unlock(void)
defer_kfree_skb_list = NULL;
+#ifdef CONFIG_RTNL_LOCK_DEBUG
+ rtnl_relase_btrace();
+#endif
+
mutex_unlock(&rtnl_mutex);
while (head) {
--
2.18.0
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply related [flat|nested] 16+ messages in thread
* [PATCH][v2] rtnetlink: add rtnl_lock debug log
@ 2021-05-08 8:57 ` Rocco Yue
0 siblings, 0 replies; 16+ messages in thread
From: Rocco Yue @ 2021-05-08 8:57 UTC (permalink / raw)
To: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, peterz
Cc: Tetsuo Handa, Peter Enderborg, Thomas Gleixner,
Anshuman Khandual, Vitor Massaru Iha, Sedat Dilek, Wei Yang,
Cong Wang, Di Zhu, Stephen Hemminger, Francis Laniel,
Roopa Prabhu, Andrii Nakryiko, linux-kernel, netdev,
linux-arm-kernel, linux-mediatek, wsd_upsream, Rocco Yue
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 --
<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]
Signed-off-by: Rocco Yue <rocco.yue@mediatek.com>
---
lib/Kconfig.debug | 10 ++++++
net/core/rtnetlink.c | 85 ++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 95 insertions(+)
diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 678c13967580..f1a722e16bee 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -2027,6 +2027,16 @@ config KCOV_IRQ_AREA_SIZE
soft interrupts. This specifies the size of those areas in the
number of unsigned long words.
+config RTNL_LOCK_DEBUG
+ bool "rtnl_lock debugging, deadlock detection"
+ depends on STACKTRACE_SUPPORT
+ select STACKTRACE
+ help
+ If you say Y here then the kernel will detect whether any function
+ hold rtnl_lock too long and some key information will be printed
+ out to help locate the problem.
+ If unsure, say N.
+
menuconfig RUNTIME_TESTING_MENU
bool "Runtime Testing"
def_bool y
diff --git a/net/core/rtnetlink.c b/net/core/rtnetlink.c
index 714d5fa38546..4f81086e5a42 100644
--- a/net/core/rtnetlink.c
+++ b/net/core/rtnetlink.c
@@ -12,6 +12,8 @@
* Vitaly E. Lavrov RTA_OK arithmetics was wrong.
*/
+#define pr_fmt(fmt) "rtnetlink: " fmt
+
#include <linux/bitops.h>
#include <linux/errno.h>
#include <linux/module.h>
@@ -57,6 +59,81 @@
#define RTNL_MAX_TYPE 50
#define RTNL_SLAVE_MAX_TYPE 40
+#ifdef CONFIG_RTNL_LOCK_DEBUG
+
+#include <linux/sched/debug.h>
+#include <linux/stacktrace.h>
+
+/* Debug log and btrace will be printed when the rtnl_lock
+ * is held for more than RTNL_LOCK_MAX_HOLD_TIME seconds
+ */
+#define RTNL_LOCK_MAX_HOLD_TIME 2
+
+#define RTNL_LOCK_MAX_TRACE 10 /* stack trace length */
+
+struct rtnl_debug_btrace_t {
+ struct task_struct *task;
+ int pid;
+ unsigned long long start_time;
+ unsigned long long end_time;
+ unsigned long addrs[RTNL_LOCK_MAX_TRACE];
+ unsigned int nr_entries;
+};
+
+static struct rtnl_debug_btrace_t rtnl_instance;
+
+static void rtnl_print_btrace(struct timer_list *unused);
+static DEFINE_TIMER(rtnl_chk_timer, rtnl_print_btrace);
+
+/* Save stack trace to the given array of RTNL_LOCK_MAX_TRACE size.
+ */
+static int __save_stack_trace(unsigned long *trace)
+{
+ return stack_trace_save(trace, RTNL_LOCK_MAX_TRACE, 0);
+}
+
+static void rtnl_get_btrace(struct task_struct *who)
+{
+ unsigned long expires;
+
+ rtnl_instance.task = who;
+ rtnl_instance.pid = who->pid;
+ rtnl_instance.start_time = sched_clock();
+ rtnl_instance.end_time = 0;
+ rtnl_instance.nr_entries = __save_stack_trace(rtnl_instance.addrs);
+
+ expires = jiffies + RTNL_LOCK_MAX_HOLD_TIME * HZ;
+ mod_timer(&rtnl_chk_timer, expires);
+}
+
+static void rtnl_print_btrace(struct timer_list *unused)
+{
+ pr_info("-- %s start --\n", __func__);
+ pr_info("%s[%d][%c] hold rtnl_lock more than %d sec, start time: %llu\n",
+ rtnl_instance.task->comm,
+ rtnl_instance.pid,
+ task_state_to_char(rtnl_instance.task),
+ RTNL_LOCK_MAX_HOLD_TIME,
+ rtnl_instance.start_time);
+ stack_trace_print(rtnl_instance.addrs, rtnl_instance.nr_entries, 0);
+ show_stack(rtnl_instance.task, NULL, KERN_INFO);
+ pr_info("-- %s end --\n", __func__);
+}
+
+static void rtnl_relase_btrace(void)
+{
+ rtnl_instance.end_time = sched_clock();
+ del_timer_sync(&rtnl_chk_timer);
+
+ if (rtnl_instance.end_time - rtnl_instance.start_time > 2 * NSEC_PER_SEC) {
+ pr_info("rtnl_lock is held by [%d] from [%llu] to [%llu]\n",
+ rtnl_instance.pid,
+ rtnl_instance.start_time,
+ rtnl_instance.end_time);
+ }
+}
+#endif
+
struct rtnl_link {
rtnl_doit_func doit;
rtnl_dumpit_func dumpit;
@@ -70,6 +147,10 @@ static DEFINE_MUTEX(rtnl_mutex);
void rtnl_lock(void)
{
mutex_lock(&rtnl_mutex);
+
+#ifdef CONFIG_RTNL_LOCK_DEBUG
+ rtnl_get_btrace(current);
+#endif
}
EXPORT_SYMBOL(rtnl_lock);
@@ -95,6 +176,10 @@ void __rtnl_unlock(void)
defer_kfree_skb_list = NULL;
+#ifdef CONFIG_RTNL_LOCK_DEBUG
+ rtnl_relase_btrace();
+#endif
+
mutex_unlock(&rtnl_mutex);
while (head) {
--
2.18.0
_______________________________________________
Linux-mediatek mailing list
Linux-mediatek@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-mediatek
^ permalink raw reply related [flat|nested] 16+ messages in thread
* Re: [PATCH][v2] rtnetlink: add rtnl_lock debug log
2021-05-08 8:57 ` Rocco Yue
(?)
@ 2021-05-09 9:42 ` Andy Shevchenko
-1 siblings, 0 replies; 16+ messages in thread
From: Andy Shevchenko @ 2021-05-09 9:42 UTC (permalink / raw)
To: Rocco Yue
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, Peter Zijlstra (Intel),
Tetsuo Handa, Peter Enderborg, Thomas Gleixner,
Anshuman Khandual, Vitor Massaru Iha, Sedat Dilek, Wei Yang,
Cong Wang, Di Zhu, Stephen Hemminger, Francis Laniel,
Roopa Prabhu, Andrii Nakryiko, Linux Kernel Mailing List, netdev,
linux-arm Mailing List, moderated list:ARM/Mediatek SoC support,
wsd_upsream
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
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH][v2] rtnetlink: add rtnl_lock debug log
@ 2021-05-09 9:42 ` Andy Shevchenko
0 siblings, 0 replies; 16+ messages in thread
From: Andy Shevchenko @ 2021-05-09 9:42 UTC (permalink / raw)
To: Rocco Yue
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, Peter Zijlstra (Intel),
Tetsuo Handa, Peter Enderborg, Thomas Gleixner,
Anshuman Khandual, Vitor Massaru Iha, Sedat Dilek, Wei Yang,
Cong Wang, Di Zhu, Stephen Hemminger, Francis Laniel,
Roopa Prabhu, Andrii Nakryiko, Linux Kernel Mailing List, netdev,
linux-arm Mailing List, moderated list:ARM/Mediatek SoC support,
wsd_upsream
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
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH][v2] rtnetlink: add rtnl_lock debug log
@ 2021-05-09 9:42 ` Andy Shevchenko
0 siblings, 0 replies; 16+ messages in thread
From: Andy Shevchenko @ 2021-05-09 9:42 UTC (permalink / raw)
To: Rocco Yue
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, Peter Zijlstra (Intel),
Tetsuo Handa, Peter Enderborg, Thomas Gleixner,
Anshuman Khandual, Vitor Massaru Iha, Sedat Dilek, Wei Yang,
Cong Wang, Di Zhu, Stephen Hemminger, Francis Laniel,
Roopa Prabhu, Andrii Nakryiko, Linux Kernel Mailing List, netdev,
linux-arm Mailing List, moderated list:ARM/Mediatek SoC support,
wsd_upsream
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
_______________________________________________
Linux-mediatek mailing list
Linux-mediatek@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-mediatek
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH][v2] rtnetlink: add rtnl_lock debug log
2021-05-09 9:42 ` Andy Shevchenko
@ 2021-05-10 7:23 ` Rocco.Yue
-1 siblings, 0 replies; 16+ messages in thread
From: Rocco.Yue @ 2021-05-10 7:23 UTC (permalink / raw)
To: Andy Shevchenko
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, Peter Zijlstra (Intel),
Tetsuo Handa, Peter Enderborg, Thomas Gleixner,
Anshuman Khandual, Vitor Massaru Iha, Sedat Dilek, Wei Yang,
Cong Wang, Di Zhu, Stephen Hemminger, Francis Laniel,
Roopa Prabhu, Andrii Nakryiko, Linux Kernel Mailing List, netdev,
linux-arm Mailing List, moderated list:ARM/Mediatek SoC support,
wsd_upsream
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@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?
>
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]
> > <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]
>
Best Regards
Rocco
_______________________________________________
Linux-mediatek mailing list
Linux-mediatek@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-mediatek
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH][v2] rtnetlink: add rtnl_lock debug log
@ 2021-05-10 7:23 ` Rocco.Yue
0 siblings, 0 replies; 16+ messages in thread
From: Rocco.Yue @ 2021-05-10 7:23 UTC (permalink / raw)
To: Andy Shevchenko
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, Peter Zijlstra (Intel),
Tetsuo Handa, Peter Enderborg, Thomas Gleixner,
Anshuman Khandual, Vitor Massaru Iha, Sedat Dilek, Wei Yang,
Cong Wang, Di Zhu, Stephen Hemminger, Francis Laniel,
Roopa Prabhu, Andrii Nakryiko, Linux Kernel Mailing List, netdev,
linux-arm Mailing List, moderated list:ARM/Mediatek SoC support,
wsd_upsream
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@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?
>
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]
> > <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]
>
Best Regards
Rocco
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH][v2] rtnetlink: add rtnl_lock debug log
2021-05-10 7:23 ` Rocco.Yue
(?)
@ 2021-05-10 12:19 ` Andy Shevchenko
-1 siblings, 0 replies; 16+ messages in thread
From: Andy Shevchenko @ 2021-05-10 12:19 UTC (permalink / raw)
To: Rocco.Yue
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Peter Zijlstra (Intel),
Tetsuo Handa, Peter Enderborg, Thomas Gleixner,
Anshuman Khandual, Vitor Massaru Iha, Sedat Dilek, Wei Yang,
Cong Wang, Di Zhu, Stephen Hemminger, Francis Laniel,
Roopa Prabhu, Andrii Nakryiko, Linux Kernel Mailing List, netdev,
linux-arm Mailing List, moderated list:ARM/Mediatek SoC support,
wsd_upsream
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@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?
> >
>
> 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
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH][v2] rtnetlink: add rtnl_lock debug log
@ 2021-05-10 12:19 ` Andy Shevchenko
0 siblings, 0 replies; 16+ messages in thread
From: Andy Shevchenko @ 2021-05-10 12:19 UTC (permalink / raw)
To: Rocco.Yue
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Peter Zijlstra (Intel),
Tetsuo Handa, Peter Enderborg, Thomas Gleixner,
Anshuman Khandual, Vitor Massaru Iha, Sedat Dilek, Wei Yang,
Cong Wang, Di Zhu, Stephen Hemminger, Francis Laniel,
Roopa Prabhu, Andrii Nakryiko, Linux Kernel Mailing List, netdev,
linux-arm Mailing List, moderated list:ARM/Mediatek SoC support,
wsd_upsream
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@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?
> >
>
> 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
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [PATCH][v2] rtnetlink: add rtnl_lock debug log
@ 2021-05-10 12:19 ` Andy Shevchenko
0 siblings, 0 replies; 16+ messages in thread
From: Andy Shevchenko @ 2021-05-10 12:19 UTC (permalink / raw)
To: Rocco.Yue
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Peter Zijlstra (Intel),
Tetsuo Handa, Peter Enderborg, Thomas Gleixner,
Anshuman Khandual, Vitor Massaru Iha, Sedat Dilek, Wei Yang,
Cong Wang, Di Zhu, Stephen Hemminger, Francis Laniel,
Roopa Prabhu, Andrii Nakryiko, Linux Kernel Mailing List, netdev,
linux-arm Mailing List, moderated list:ARM/Mediatek SoC support,
wsd_upsream
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@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?
> >
>
> 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
_______________________________________________
Linux-mediatek mailing list
Linux-mediatek@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-mediatek
^ permalink raw reply [flat|nested] 16+ messages in thread
* Aw: [PATCH][v2] rtnetlink: add rtnl_lock debug log
2021-05-08 8:57 ` Rocco Yue
(?)
@ 2021-05-11 18:54 ` Frank Wunderlich
-1 siblings, 0 replies; 16+ messages in thread
From: Frank Wunderlich @ 2021-05-11 18:54 UTC (permalink / raw)
To: Rocco Yue
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, peterz, Tetsuo Handa, Peter Enderborg,
Thomas Gleixner, Anshuman Khandual, Vitor Massaru Iha,
Sedat Dilek, Wei Yang, Cong Wang, Di Zhu, Stephen Hemminger,
Francis Laniel, Roopa Prabhu, Andrii Nakryiko, linux-kernel,
netdev, linux-arm-kernel, linux-mediatek, wsd_upsream, Rocco Yue
> Gesendet: Samstag, 08. Mai 2021 um 10:57 Uhr
> Von: "Rocco Yue" <rocco.yue@mediatek.com>
> Betreff: [PATCH][v2] rtnetlink: add rtnl_lock debug log
> <6>[ 40.191481][ C6] rtnetlink: -- rtnl_print_btrace start --
> <6>[ 40.191494][ C6] rtnetlink: RfxSender_4[2206][R] hold rtnl_lock
> more than 2 sec, start time: 38181400013
it would be good to have same time-format (seconds.nanosec)
> <6>[ 42.181879][ T2206] rtnetlink: rtnl_lock is held by [2206] from
> [38181400013] to [42181875177]
same as above
> +static void rtnl_relase_btrace(void)
should this be release_btrace?
regards Frank
^ permalink raw reply [flat|nested] 16+ messages in thread
* Aw: [PATCH][v2] rtnetlink: add rtnl_lock debug log
@ 2021-05-11 18:54 ` Frank Wunderlich
0 siblings, 0 replies; 16+ messages in thread
From: Frank Wunderlich @ 2021-05-11 18:54 UTC (permalink / raw)
To: Rocco Yue
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, peterz, Tetsuo Handa, Peter Enderborg,
Thomas Gleixner, Anshuman Khandual, Vitor Massaru Iha,
Sedat Dilek, Wei Yang, Cong Wang, Di Zhu, Stephen Hemminger,
Francis Laniel, Roopa Prabhu, Andrii Nakryiko, linux-kernel,
netdev, linux-arm-kernel, linux-mediatek, wsd_upsream, Rocco Yue
> Gesendet: Samstag, 08. Mai 2021 um 10:57 Uhr
> Von: "Rocco Yue" <rocco.yue@mediatek.com>
> Betreff: [PATCH][v2] rtnetlink: add rtnl_lock debug log
> <6>[ 40.191481][ C6] rtnetlink: -- rtnl_print_btrace start --
> <6>[ 40.191494][ C6] rtnetlink: RfxSender_4[2206][R] hold rtnl_lock
> more than 2 sec, start time: 38181400013
it would be good to have same time-format (seconds.nanosec)
> <6>[ 42.181879][ T2206] rtnetlink: rtnl_lock is held by [2206] from
> [38181400013] to [42181875177]
same as above
> +static void rtnl_relase_btrace(void)
should this be release_btrace?
regards Frank
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 16+ messages in thread
* Aw: [PATCH][v2] rtnetlink: add rtnl_lock debug log
@ 2021-05-11 18:54 ` Frank Wunderlich
0 siblings, 0 replies; 16+ messages in thread
From: Frank Wunderlich @ 2021-05-11 18:54 UTC (permalink / raw)
To: Rocco Yue
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, peterz, Tetsuo Handa, Peter Enderborg,
Thomas Gleixner, Anshuman Khandual, Vitor Massaru Iha,
Sedat Dilek, Wei Yang, Cong Wang, Di Zhu, Stephen Hemminger,
Francis Laniel, Roopa Prabhu, Andrii Nakryiko, linux-kernel,
netdev, linux-arm-kernel, linux-mediatek, wsd_upsream, Rocco Yue
> Gesendet: Samstag, 08. Mai 2021 um 10:57 Uhr
> Von: "Rocco Yue" <rocco.yue@mediatek.com>
> Betreff: [PATCH][v2] rtnetlink: add rtnl_lock debug log
> <6>[ 40.191481][ C6] rtnetlink: -- rtnl_print_btrace start --
> <6>[ 40.191494][ C6] rtnetlink: RfxSender_4[2206][R] hold rtnl_lock
> more than 2 sec, start time: 38181400013
it would be good to have same time-format (seconds.nanosec)
> <6>[ 42.181879][ T2206] rtnetlink: rtnl_lock is held by [2206] from
> [38181400013] to [42181875177]
same as above
> +static void rtnl_relase_btrace(void)
should this be release_btrace?
regards Frank
_______________________________________________
Linux-mediatek mailing list
Linux-mediatek@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-mediatek
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Aw: [PATCH][v2] rtnetlink: add rtnl_lock debug log
2021-05-11 18:54 ` Frank Wunderlich
@ 2021-05-12 8:48 ` Rocco.Yue
-1 siblings, 0 replies; 16+ messages in thread
From: Rocco.Yue @ 2021-05-12 8:48 UTC (permalink / raw)
To: Frank Wunderlich
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, peterz, Tetsuo Handa, Peter Enderborg,
Thomas Gleixner, Anshuman Khandual, Vitor Massaru Iha,
Sedat Dilek, Wei Yang, Cong Wang, Di Zhu, Stephen Hemminger,
Francis Laniel, Roopa Prabhu, Andrii Nakryiko, linux-kernel,
netdev, linux-arm-kernel, linux-mediatek, wsd_upsream
On Tue, 2021-05-11 at 20:54 +0200, Frank Wunderlich wrote:
> > Gesendet: Samstag, 08. Mai 2021 um 10:57 Uhr
> > Von: "Rocco Yue" <rocco.yue@mediatek.com>
> > Betreff: [PATCH][v2] rtnetlink: add rtnl_lock debug log
>
> > <6>[ 40.191481][ C6] rtnetlink: -- rtnl_print_btrace start --
> > <6>[ 40.191494][ C6] rtnetlink: RfxSender_4[2206][R] hold rtnl_lock
> > more than 2 sec, start time: 38181400013
> it would be good to have same time-format (seconds.nanosec)
>
> > <6>[ 42.181879][ T2206] rtnetlink: rtnl_lock is held by [2206] from
> > [38181400013] to [42181875177]
> same as above
>
Thanks for your review.
I have also thought about whether it needs to be modified here, and the
intuitive reading here will be a little troubled. It is ok for me to
modify :-)
> > +static void rtnl_relase_btrace(void)
> should this be release_btrace?
>
will fix.
Best Regards
Rocco
_______________________________________________
Linux-mediatek mailing list
Linux-mediatek@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-mediatek
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: Aw: [PATCH][v2] rtnetlink: add rtnl_lock debug log
@ 2021-05-12 8:48 ` Rocco.Yue
0 siblings, 0 replies; 16+ messages in thread
From: Rocco.Yue @ 2021-05-12 8:48 UTC (permalink / raw)
To: Frank Wunderlich
Cc: David S . Miller, Jakub Kicinski, Matthias Brugger,
Andrew Morton, Masahiro Yamada, Nick Desaulniers,
Andy Shevchenko, peterz, Tetsuo Handa, Peter Enderborg,
Thomas Gleixner, Anshuman Khandual, Vitor Massaru Iha,
Sedat Dilek, Wei Yang, Cong Wang, Di Zhu, Stephen Hemminger,
Francis Laniel, Roopa Prabhu, Andrii Nakryiko, linux-kernel,
netdev, linux-arm-kernel, linux-mediatek, wsd_upsream
On Tue, 2021-05-11 at 20:54 +0200, Frank Wunderlich wrote:
> > Gesendet: Samstag, 08. Mai 2021 um 10:57 Uhr
> > Von: "Rocco Yue" <rocco.yue@mediatek.com>
> > Betreff: [PATCH][v2] rtnetlink: add rtnl_lock debug log
>
> > <6>[ 40.191481][ C6] rtnetlink: -- rtnl_print_btrace start --
> > <6>[ 40.191494][ C6] rtnetlink: RfxSender_4[2206][R] hold rtnl_lock
> > more than 2 sec, start time: 38181400013
> it would be good to have same time-format (seconds.nanosec)
>
> > <6>[ 42.181879][ T2206] rtnetlink: rtnl_lock is held by [2206] from
> > [38181400013] to [42181875177]
> same as above
>
Thanks for your review.
I have also thought about whether it needs to be modified here, and the
intuitive reading here will be a little troubled. It is ok for me to
modify :-)
> > +static void rtnl_relase_btrace(void)
> should this be release_btrace?
>
will fix.
Best Regards
Rocco
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 16+ messages in thread