Files
twx-linux/include/linux
Adrian Huang f9a18889aa mm/vmalloc: combine all TLB flush operations of KASAN shadow virtual address into one operation
commit 9e9e085eff upstream.

When compiling kernel source 'make -j $(nproc)' with the up-and-running
KASAN-enabled kernel on a 256-core machine, the following soft lockup is
shown:

watchdog: BUG: soft lockup - CPU#28 stuck for 22s! [kworker/28:1:1760]
CPU: 28 PID: 1760 Comm: kworker/28:1 Kdump: loaded Not tainted 6.10.0-rc5 #95
Workqueue: events drain_vmap_area_work
RIP: 0010:smp_call_function_many_cond+0x1d8/0xbb0
Code: 38 c8 7c 08 84 c9 0f 85 49 08 00 00 8b 45 08 a8 01 74 2e 48 89 f1 49 89 f7 48 c1 e9 03 41 83 e7 07 4c 01 e9 41 83 c7 03 f3 90 <0f> b6 01 41 38 c7 7c 08 84 c0 0f 85 d4 06 00 00 8b 45 08 a8 01 75
RSP: 0018:ffffc9000cb3fb60 EFLAGS: 00000202
RAX: 0000000000000011 RBX: ffff8883bc4469c0 RCX: ffffed10776e9949
RDX: 0000000000000002 RSI: ffff8883bb74ca48 RDI: ffffffff8434dc50
RBP: ffff8883bb74ca40 R08: ffff888103585dc0 R09: ffff8884533a1800
R10: 0000000000000004 R11: ffffffffffffffff R12: ffffed1077888d39
R13: dffffc0000000000 R14: ffffed1077888d38 R15: 0000000000000003
FS:  0000000000000000(0000) GS:ffff8883bc400000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00005577b5c8d158 CR3: 0000000004850000 CR4: 0000000000350ef0
Call Trace:
 <IRQ>
 ? watchdog_timer_fn+0x2cd/0x390
 ? __pfx_watchdog_timer_fn+0x10/0x10
 ? __hrtimer_run_queues+0x300/0x6d0
 ? sched_clock_cpu+0x69/0x4e0
 ? __pfx___hrtimer_run_queues+0x10/0x10
 ? srso_return_thunk+0x5/0x5f
 ? ktime_get_update_offsets_now+0x7f/0x2a0
 ? srso_return_thunk+0x5/0x5f
 ? srso_return_thunk+0x5/0x5f
 ? hrtimer_interrupt+0x2ca/0x760
 ? __sysvec_apic_timer_interrupt+0x8c/0x2b0
 ? sysvec_apic_timer_interrupt+0x6a/0x90
 </IRQ>
 <TASK>
 ? asm_sysvec_apic_timer_interrupt+0x16/0x20
 ? smp_call_function_many_cond+0x1d8/0xbb0
 ? __pfx_do_kernel_range_flush+0x10/0x10
 on_each_cpu_cond_mask+0x20/0x40
 flush_tlb_kernel_range+0x19b/0x250
 ? srso_return_thunk+0x5/0x5f
 ? kasan_release_vmalloc+0xa7/0xc0
 purge_vmap_node+0x357/0x820
 ? __pfx_purge_vmap_node+0x10/0x10
 __purge_vmap_area_lazy+0x5b8/0xa10
 drain_vmap_area_work+0x21/0x30
 process_one_work+0x661/0x10b0
 worker_thread+0x844/0x10e0
 ? srso_return_thunk+0x5/0x5f
 ? __kthread_parkme+0x82/0x140
 ? __pfx_worker_thread+0x10/0x10
 kthread+0x2a5/0x370
 ? __pfx_kthread+0x10/0x10
 ret_from_fork+0x30/0x70
 ? __pfx_kthread+0x10/0x10
 ret_from_fork_asm+0x1a/0x30
 </TASK>

Debugging Analysis:

  1. The following ftrace log shows that the lockup CPU spends too much
     time iterating vmap_nodes and flushing TLB when purging vm_area
     structures. (Some info is trimmed).

     kworker: funcgraph_entry:              |  drain_vmap_area_work() {
     kworker: funcgraph_entry:              |   mutex_lock() {
     kworker: funcgraph_entry:  1.092 us    |     __cond_resched();
     kworker: funcgraph_exit:   3.306 us    |   }
     ...                                        ...
     kworker: funcgraph_entry:              |    flush_tlb_kernel_range() {
     ...                                          ...
     kworker: funcgraph_exit: # 7533.649 us |    }
     ...                                         ...
     kworker: funcgraph_entry:  2.344 us    |   mutex_unlock();
     kworker: funcgraph_exit: $ 23871554 us | }

     The drain_vmap_area_work() spends over 23 seconds.

     There are 2805 flush_tlb_kernel_range() calls in the ftrace log.
       * One is called in __purge_vmap_area_lazy().
       * Others are called by purge_vmap_node->kasan_release_vmalloc.
         purge_vmap_node() iteratively releases kasan vmalloc
         allocations and flushes TLB for each vmap_area.
           - [Rough calculation] Each flush_tlb_kernel_range() runs
             about 7.5ms.
               -- 2804 * 7.5ms = 21.03 seconds.
               -- That's why a soft lock is triggered.

  2. Extending the soft lockup time can work around the issue (For example,
     # echo 60 > /proc/sys/kernel/watchdog_thresh). This confirms the
     above-mentioned speculation: drain_vmap_area_work() spends too much
     time.

If we combine all TLB flush operations of the KASAN shadow virtual
address into one operation in the call path
'purge_vmap_node()->kasan_release_vmalloc()', the running time of
drain_vmap_area_work() can be saved greatly. The idea is from the
flush_tlb_kernel_range() call in __purge_vmap_area_lazy(). And, the
soft lockup won't be triggered.

Here is the test result based on 6.10:

[6.10 wo/ the patch]
  1. ftrace latency profiling (record a trace if the latency > 20s).
     echo 20000000 > /sys/kernel/debug/tracing/tracing_thresh
     echo drain_vmap_area_work > /sys/kernel/debug/tracing/set_graph_function
     echo function_graph > /sys/kernel/debug/tracing/current_tracer
     echo 1 > /sys/kernel/debug/tracing/tracing_on

  2. Run `make -j $(nproc)` to compile the kernel source

  3. Once the soft lockup is reproduced, check the ftrace log:
     cat /sys/kernel/debug/tracing/trace
        # tracer: function_graph
        #
        # CPU  DURATION                  FUNCTION CALLS
        # |     |   |                     |   |   |   |
          76) $ 50412985 us |    } /* __purge_vmap_area_lazy */
          76) $ 50412997 us |  } /* drain_vmap_area_work */
          76) $ 29165911 us |    } /* __purge_vmap_area_lazy */
          76) $ 29165926 us |  } /* drain_vmap_area_work */
          91) $ 53629423 us |    } /* __purge_vmap_area_lazy */
          91) $ 53629434 us |  } /* drain_vmap_area_work */
          91) $ 28121014 us |    } /* __purge_vmap_area_lazy */
          91) $ 28121026 us |  } /* drain_vmap_area_work */

[6.10 w/ the patch]
  1. Repeat step 1-2 in "[6.10 wo/ the patch]"

  2. The soft lockup is not triggered and ftrace log is empty.
     cat /sys/kernel/debug/tracing/trace
     # tracer: function_graph
     #
     # CPU  DURATION                  FUNCTION CALLS
     # |     |   |                     |   |   |   |

  3. Setting 'tracing_thresh' to 10/5 seconds does not get any ftrace
     log.

  4. Setting 'tracing_thresh' to 1 second gets ftrace log.
     cat /sys/kernel/debug/tracing/trace
     # tracer: function_graph
     #
     # CPU  DURATION                  FUNCTION CALLS
     # |     |   |                     |   |   |   |
       23) $ 1074942 us  |    } /* __purge_vmap_area_lazy */
       23) $ 1074950 us  |  } /* drain_vmap_area_work */

  The worst execution time of drain_vmap_area_work() is about 1 second.

Link: https://lore.kernel.org/lkml/ZqFlawuVnOMY2k3E@pc638.lan/
Link: https://lkml.kernel.org/r/20240726165246.31326-1-ahuang12@lenovo.com
Fixes: 282631cb24 ("mm: vmalloc: remove global purge_vmap_area_root rb-tree")
Signed-off-by: Adrian Huang <ahuang12@lenovo.com>
Co-developed-by: Uladzislau Rezki (Sony) <urezki@gmail.com>
Signed-off-by: Uladzislau Rezki (Sony) <urezki@gmail.com>
Tested-by: Jiwei Sun <sunjw10@lenovo.com>
Reviewed-by: Baoquan He <bhe@redhat.com>
Cc: Alexander Potapenko <glider@google.com>
Cc: Andrey Konovalov <andreyknvl@gmail.com>
Cc: Andrey Ryabinin <ryabinin.a.a@gmail.com>
Cc: Christoph Hellwig <hch@infradead.org>
Cc: Dmitry Vyukov <dvyukov@google.com>
Cc: Vincenzo Frascino <vincenzo.frascino@arm.com>
Cc: <stable@vger.kernel.org>
Signed-off-by: Andrew Morton <akpm@linux-foundation.org>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
2024-12-09 10:41:08 +01:00
..
2024-12-05 14:01:23 +01:00
2022-01-22 08:33:34 +02:00
2021-05-06 19:24:11 -07:00
2023-12-20 19:26:32 -05:00
2020-05-24 20:48:11 +02:00
2024-08-29 04:32:32 -06:00
2024-08-28 06:53:58 -07:00
2024-07-08 01:51:05 -06:00
2023-12-15 16:25:55 -08:00
2024-09-03 21:15:36 -07:00
2024-06-24 18:29:20 +02:00
2024-04-23 09:03:37 +09:00
2023-04-17 18:01:23 +02:00
2024-06-11 12:57:49 -05:00
2024-02-20 14:22:55 -05:00
2024-02-20 14:22:51 -05:00
2019-12-03 11:20:37 +01:00
2021-08-26 15:32:28 -04:00
2018-01-01 12:40:27 -07:00
2021-07-27 11:00:36 +02:00
2024-10-01 17:01:40 +02:00
2024-05-19 14:36:17 -07:00
2020-03-06 11:06:15 +01:00
2024-09-09 16:39:05 -07:00
2019-02-15 16:54:38 +01:00
2022-01-20 08:52:54 +02:00
2021-07-27 20:11:45 +01:00
2021-07-27 20:11:44 +01:00
2024-08-29 10:39:37 +02:00
2010-02-09 11:13:56 +01:00
2023-05-01 17:50:18 -07:00
2020-07-24 17:12:41 -07:00
2019-06-26 13:19:46 -07:00
2024-02-28 19:36:39 -08:00
2024-08-23 20:50:19 +02:00
2024-02-14 11:14:40 +01:00
2023-12-20 19:26:31 -05:00
2024-07-31 13:49:48 +01:00
2024-08-08 17:15:02 +02:00
2024-06-24 22:24:56 -07:00
2024-09-03 21:15:46 -07:00
2019-12-11 09:12:38 +01:00
2024-09-20 18:28:26 +03:00
2024-09-01 20:26:03 -07:00
2024-09-09 16:39:04 -07:00
2024-07-03 19:30:23 -07:00
2024-02-17 16:20:41 +01:00
2021-02-26 09:41:03 -08:00
2023-10-18 14:43:21 -07:00
2023-10-04 10:41:57 -07:00
2023-12-20 19:26:30 -05:00
2024-05-03 10:44:42 +01:00
2023-10-16 12:44:06 -04:00
2019-03-07 18:32:03 -08:00
2024-08-11 17:04:29 +01:00
2024-07-31 09:57:18 -07:00
2022-07-27 14:04:52 +02:00
2022-08-02 12:34:04 -04:00
2023-06-20 20:17:10 -07:00
2018-10-17 13:56:58 -07:00
2024-07-28 16:47:51 -06:00
2024-09-23 15:03:30 -04:00
2024-06-24 22:25:02 -07:00
2022-09-26 19:46:27 -07:00
2021-09-17 13:52:17 +01:00
2024-03-26 11:07:20 -07:00
2021-02-03 19:05:50 +01:00
2024-08-30 08:22:38 +02:00
2021-09-27 17:00:21 +02:00
2024-09-19 14:25:34 -05:00
2024-09-17 01:06:59 -07:00
2024-03-13 12:53:53 -07:00
2024-03-13 12:53:53 -07:00
2023-12-20 19:26:30 -05:00
2023-08-12 09:18:47 -07:00
2024-09-05 11:14:14 +02:00
2023-05-23 12:55:12 -07:00
2022-03-08 14:33:36 -06:00
2024-04-02 18:03:32 -07:00
2023-07-15 11:34:49 -07:00
2023-12-27 11:49:56 -05:00
2023-12-20 19:26:31 -05:00
2024-03-08 12:05:10 +01:00
2024-04-03 09:59:38 +01:00
2023-12-20 19:26:32 -05:00
2023-12-20 19:26:32 -05:00
2023-01-19 15:01:19 +01:00
2024-04-09 10:53:44 +02:00
2020-12-10 16:17:15 +01:00
2024-09-11 20:44:32 -07:00
2024-08-12 23:50:58 +05:30
2021-08-19 09:02:55 +09:00
2024-05-04 18:57:21 +02:00
2023-10-18 14:43:21 -07:00
2022-09-07 12:42:25 +01:00
2023-08-21 13:37:26 -07:00
2024-07-10 07:59:03 +02:00
2022-09-29 15:20:29 +02:00
2024-04-08 11:49:02 +01:00
2020-10-30 21:57:04 +01:00
2024-05-06 12:05:00 +02:00
2024-08-06 13:42:40 +02:00
2024-09-12 12:20:39 +02:00
2021-10-12 11:41:39 -03:00
2023-03-23 17:25:46 +01:00
2023-08-24 13:27:47 -05:00
2024-09-01 20:25:43 -07:00
2023-04-21 03:02:34 -04:00
2024-02-09 12:07:48 +00:00
2024-04-25 20:55:48 -07:00