BUG: bpf: task hung in lock_sock_nested during sockmap free

BUG: bpf: task hung in lock_sock_nested during sockmap free

[Kenneth Lee]

Hi,

The following hung task was found by a custom fuzzer developed
by Sechang Lim <rhkrqnwk98@gmail.com>:

  INFO: task kworker/u8:19:1912 blocked for more than 122 seconds.

Unfortunately, we haven't found a reproducer for the hang yet. We'll
inform you if we have any update on the hang.

Detailed crash information is attached below.

Thanks,
Kenneth Lee

---
- Kernel version:
7.1.0-rc6

- Crash Report:
INFO: task kworker/u8:19:1912 blocked for more than 122 seconds.
      Not tainted 7.1.0-rc6-dirty #34
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/u8:19   state:D stack:24296 pid:1912  tgid:1912  ppid:2      task_flags:0x4208060 flags:0x00080000
Workqueue: events_unbound bpf_map_free_deferred
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5388 [inline]
 __schedule+0x1f31/0x2e80 kernel/sched/core.c:7189
 __schedule_loop kernel/sched/core.c:7268 [inline]
 schedule+0x167/0x360 kernel/sched/core.c:7283
 __lock_sock+0xf5/0x210 net/core/sock.c:3191
 lock_sock_nested+0xca/0x100 net/core/sock.c:3804
 lock_sock include/net/sock.h:1713 [inline]
 sock_map_free+0x120/0x3c0 net/core/sock_map.c:356
 bpf_map_free+0x197/0x3c0 kernel/bpf/syscall.c:892
 process_one_work kernel/workqueue.c:3314 [inline]
 process_scheduled_works+0xa98/0x1690 kernel/workqueue.c:3397
 worker_thread+0x8a5/0xd90 kernel/workqueue.c:3478
 kthread+0x397/0x480 kernel/kthread.c:436
 ret_from_fork+0x397/0x810 arch/x86/kernel/process.c:158
 ret_from_fork_asm+0x1a/0x30 arch/x86/entry/entry_64.S:245
 </TASK>

Showing all locks held in the system:
1 lock held by khungtaskd/34:
 #0: ffffffffa4905880 (rcu_read_lock){....}-{1:3}, at: rcu_lock_acquire include/linux/rcupdate.h:300 [inline]
 #0: ffffffffa4905880 (rcu_read_lock){....}-{1:3}, at: rcu_read_lock include/linux/rcupdate.h:838 [inline]
 #0: ffffffffa4905880 (rcu_read_lock){....}-{1:3}, at: debug_show_all_locks+0x2e/0x180 kernel/locking/lockdep.c:6775
3 locks held by systemd-journal/120:
1 lock held by syz-executor/327:
3 locks held by kworker/u8:19/1912:
 #0: ffff8881000ac140 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3289 [inline]
 #0: ffff8881000ac140 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_scheduled_works+0x9af/0x1690 kernel/workqueue.c:3397
 #1: ffffc9001279fd20 ((work_completion)(&map->work)){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3290 [inline]
 #1: ffffc9001279fd20 ((work_completion)(&map->work)){+.+.}-{0:0}, at: process_scheduled_works+0x9d6/0x1690 kernel/workqueue.c:3397
 #2: ffff888118685d58 (sk_lock-AF_INET){+.+.}-{0:0}, at: lock_sock include/net/sock.h:1713 [inline]
 #2: ffff888118685d58 (sk_lock-AF_INET){+.+.}-{0:0}, at: sock_map_free+0x120/0x3c0 net/core/sock_map.c:356
2 locks held by syz.0.944/7410:
4 locks held by syz-executor/7721:
 #0: ffff88811a93a8a0 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested kernel/sched/core.c:652 [inline]
 #0: ffff88811a93a8a0 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock kernel/sched/sched.h:1624 [inline]
 #0: ffff88811a93a8a0 (&rq->__lock){-.-.}-{2:2}, at: rq_lock kernel/sched/sched.h:1968 [inline]
 #0: ffff88811a93a8a0 (&rq->__lock){-.-.}-{2:2}, at: __schedule+0x305/0x2e80 kernel/sched/core.c:7064
 #1: ffffffffa87c6018 (&obj_hash[i].lock){-.-.}-{2:2}, at: debug_object_activate+0x87/0x540 lib/debugobjects.c:845
 #2: ffffffffa87ef238 (&obj_hash[i].lock){-.-.}-{2:2}, at: debug_object_activate+0x87/0x540 lib/debugobjects.c:845
 #3: ffff88811a934228 (lock#3){+.+.}-{3:3}, at: local_lock_acquire include/linux/local_lock_internal.h:46 [inline]
 #3: ffff88811a934228 (lock#3){+.+.}-{3:3}, at: __folio_batch_add_and_move+0x93/0x810 mm/swap.c:192
1 lock held by (udev-worker)/8332:
2 locks held by kworker/u8:9/11248:
 #0: ffff8881000ac140 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3289 [inline]
 #0: ffff8881000ac140 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_scheduled_works+0x9af/0x1690 kernel/workqueue.c:3397
 #1: ffffc9000f397d20 ((work_completion)(&map->work)){+.+.}-{0:0}, at: process_one_work kernel/workqueue.c:3290 [inline]
 #1: ffffc9000f397d20 ((work_completion)(&map->work)){+.+.}-{0:0}, at: process_scheduled_works+0x9d6/0x1690 kernel/workqueue.c:3397
1 lock held by syz.3.2068/11361:
 #0: ffffffffa50cd460 (rtnl_mutex){+.+.}-{4:4}, at: tcx_link_release+0x6e/0x4b0 kernel/bpf/tcx.c:177

Re: BUG: bpf: task hung in lock_sock_nested during sockmap free

[Kenneth Lee]

Hi,

After further analysis, we found that this report is triggered by an
SK_MSG BPF program repeatedly calling bpf_msg_apply_bytes(msg, 1).

For a message of about 557 KiB, this results in approximately 557,000
one-byte verdict and push iterations. The TCP BPF send path keeps the
socket lock while processing these iterations, so deferred
sock_map_free() waits for the same socket lock.

This appears to be a long lock-held processing path triggered by a valid
but very unrealistic msg_apply_bytes(1) workload. We believe this behavior
is benign, but let us know if other behavior is expected.

Thanks,
Kenneth Lee

Re: BUG: bpf: task hung in lock_sock_nested during sockmap free

[Jakub Sitnicki]

On Thu, Aug 20, 2026 at 11:28 AM +09, Kenneth Lee wrote:
> After further analysis, we found that this report is triggered by an
> SK_MSG BPF program repeatedly calling bpf_msg_apply_bytes(msg, 1).
>
> For a message of about 557 KiB, this results in approximately 557,000
> one-byte verdict and push iterations. The TCP BPF send path keeps the
> socket lock while processing these iterations, so deferred
> sock_map_free() waits for the same socket lock.
>
> This appears to be a long lock-held processing path triggered by a valid
> but very unrealistic msg_apply_bytes(1) workload. We believe this behavior
> is benign, but let us know if other behavior is expected.

Thanks for the follow up.

Perhaps that is a convoluted scenario but what caught my attention is
that if you got the hung task notification after ~120 seconds, and it
took ~500k prog runs to trigger it, then something seems quite slow
because we're talking ~240 usec/prog run.

If you have the repro still at hand, it might be worth to take a look at
the CPU trace [1] or a Flamegraph [2] to see where the CPU time goes.

-jkbs

[1] https://perfetto.dev/docs/getting-started/system-tracing
[2] https://www.brendangregg.com/FlameGraphs/cpuflamegraphs.html