Re: [PATCH] lib/vsprintf: Validate sleepable context during restrictred pointer formatting

[kernel test robot]

Hello,

kernel test robot noticed "BUG:sleeping_function_called_from_invalid_context_at_lib/vsprintf.c" on:

commit: a3aa148a203538960cf380021ba5605a35dd573b ("[PATCH] lib/vsprintf: Validate sleepable context during restrictred pointer formatting")
url: https://github.com/intel-lab-lkp/linux/commits/Thomas-Wei-schuh/lib-vsprintf-Validate-sleepable-context-during-restrictred-pointer-formatting/20260318-000650
patch link: https://lore.kernel.org/all/20260317-restricted-pointers-final-v1-1-b4dca0ed6483@xxxxxxxxxxxxx/
patch subject: [PATCH] lib/vsprintf: Validate sleepable context during restrictred pointer formatting

in testcase: trinity
version: 
with following parameters:

	runtime: 300s
	group: group-00
	nr_groups: 5



config: x86_64-kexec
compiler: clang-20
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 32G

(please refer to attached dmesg/kmsg for entire log/backtrace)


+---------------------------------------------------------------------+------------+------------+
|                                                                     | 2d1373e424 | a3aa148a20 |
+---------------------------------------------------------------------+------------+------------+
| BUG:sleeping_function_called_from_invalid_context_at_lib/vsprintf.c | 0          | 12         |
+---------------------------------------------------------------------+------------+------------+

If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@xxxxxxxxx>
| Closes: https://lore.kernel.org/oe-lkp/202603191629.80fc4e2b-lkp@xxxxxxxxx



[  103.203896][ T6289] BUG: sleeping function called from invalid context at lib/vsprintf.c:866
[  103.218966][ T6289] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 6289, name: trinity-c6
[  103.270174][ T6289] preempt_count: 2, expected: 0
[  103.288514][ T6289] RCU nest depth: 0, expected: 0
[  103.310869][ T6289] CPU: 1 UID: 65534 PID: 6289 Comm: trinity-c6 Not tainted 7.0.0-rc4-00006-ga3aa148a2035 #1 PREEMPT(lazy)
[  103.310904][ T6289] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-debian-1.16.3-2 04/01/2014
[  103.310929][ T6289] Call Trace:
[  103.311096][ T6289]  <TASK>
[  103.311126][ T6289]  dump_stack_lvl (lib/dump_stack.c:123)
[  103.311160][ T6289]  __might_resched (kernel/sched/core.c:8889)
[  103.311196][ T6289]  restricted_pointer (include/linux/kernel.h:58 lib/vsprintf.c:866)
[  103.311228][ T6289]  pointer (lib/vsprintf.c:2624)
[  103.311261][ T6289]  ? vsnprintf (lib/vsprintf.c:?)
[  103.311295][ T6289]  vsnprintf (lib/vsprintf.c:2955)
[  103.311327][ T6289]  seq_vprintf (fs/seq_file.c:393)
[  103.311359][ T6289]  seq_printf (fs/seq_file.c:409)
[  103.311388][ T6289]  ? rep_movs_alternative (arch/x86/lib/copy_user_64.S:46)
[  103.311423][ T6289]  unix_seq_show (net/unix/af_unix.c:3540)
[  103.311458][ T6289]  seq_read_iter (fs/seq_file.c:273)
[  103.311491][ T6289]  seq_read (fs/seq_file.c:164)
[  103.311524][ T6289]  proc_reg_read (fs/proc/inode.c:308 fs/proc/inode.c:320)
[  103.311580][ T6289]  vfs_read (fs/read_write.c:572)
[  103.311611][ T6289]  ? do_setitimer (include/linux/spinlock.h:?)
[  103.311643][ T6289]  ksys_read (fs/read_write.c:717)
[  103.311674][ T6289]  do_syscall_64 (arch/x86/entry/syscall_64.c:?)
[  103.311708][ T6289]  entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:130)
[  103.311739][ T6289] RIP: 0033:0x453b29
[  103.311749][ T6289] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 3b 84 00 00 c3 66 2e 0f 1f 84 00 00 00 00
All code
========
   0:	00 f3                	add    %dh,%bl
   2:	c3                   	ret
   3:	66 2e 0f 1f 84 00 00 	cs nopw 0x0(%rax,%rax,1)
   a:	00 00 00 
   d:	0f 1f 40 00          	nopl   0x0(%rax)
  11:	48 89 f8             	mov    %rdi,%rax
  14:	48 89 f7             	mov    %rsi,%rdi
  17:	48 89 d6             	mov    %rdx,%rsi
  1a:	48 89 ca             	mov    %rcx,%rdx
  1d:	4d 89 c2             	mov    %r8,%r10
  20:	4d 89 c8             	mov    %r9,%r8
  23:	4c 8b 4c 24 08       	mov    0x8(%rsp),%r9
  28:	0f 05                	syscall
  2a:*	48 3d 01 f0 ff ff    	cmp    $0xfffffffffffff001,%rax		<-- trapping instruction
  30:	0f 83 3b 84 00 00    	jae    0x8471
  36:	c3                   	ret
  37:	66                   	data16
  38:	2e                   	cs
  39:	0f                   	.byte 0xf
  3a:	1f                   	(bad)
  3b:	84 00                	test   %al,(%rax)
  3d:	00 00                	add    %al,(%rax)
	...

Code starting with the faulting instruction
===========================================
   0:	48 3d 01 f0 ff ff    	cmp    $0xfffffffffffff001,%rax
   6:	0f 83 3b 84 00 00    	jae    0x8447
   c:	c3                   	ret
   d:	66                   	data16
   e:	2e                   	cs
   f:	0f                   	.byte 0xf
  10:	1f                   	(bad)
  11:	84 00                	test   %al,(%rax)
  13:	00 00                	add    %al,(%rax)
	...
[  103.311777][ T6289] RSP: 002b:00007ffe20169d38 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[  103.311807][ T6289] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000453b29
[  103.311812][ T6289] RDX: 0000000000001000 RSI: 00007f14e38d0000 RDI: 00000000000000b6
[  103.311837][ T6289] RBP: 00007ffe20169de0 R08: 000000000000ffff R09: 23c080ca08458805
[  103.311842][ T6289] R10: fffffffffffffffd R11: 0000000000000246 R12: 0000000000000002
[  103.311846][ T6289] R13: 00007f14e41df058 R14: 00000000010a2830 R15: 00007f14e41df000
[  103.311877][ T6289]  </TASK>



The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20260319/202603191629.80fc4e2b-lkp@xxxxxxxxx



-- 
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki