Re: [PATCH] net: tls: enable __GFP_ZERO upon tls_init()

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On 2023/07/01 13:12, Tetsuo Handa wrote:
> Then, where does the difference between
> 
> ----------------------------------------
> [  162.919587][ T3399] required_size=10653 ret=0
> [  162.923090][ T3399] required_size=14749 ret=0
> [  162.928686][ T3399] required_size=16413 ret=0
> ----------------------------------------
> 
> and
> 
> ----------------------------------------
> [  162.992866][ T3399] required_size=10653 ret=0
> [  162.999962][ T3399] required_size=14765 ret=0
> [  163.006420][ T3399] required_size=16413 ret=0
> ----------------------------------------
> 
> come from? Both output had the same values until 10653, but
> the next value differs by 16. This might suggest that a race between
> splice() and sendmsg() caused unexpected required_size= value...
> 

I found a simplified reproducer.
This problem happens when splice() and sendmsg() run in parallel.

----------------------------------------
#define _GNU_SOURCE
#include <sys/types.h>
#include <fcntl.h>
#include <unistd.h>
#include <sys/socket.h>
#include <arpa/inet.h>
#include <sys/poll.h>
#define SOL_TCP 6
#define TCP_REPAIR 19
#define TCP_ULP 31
#define TLS_TX 1

int main(int argc, char *argv[])
{
	struct iovec iov = {
		.iov_base = "@@@@@@@@@@@@@@@@",
		.iov_len = 16
	};
	struct msghdr hdr = {
		.msg_iov = &iov,
		.msg_iovlen = 1,
		.msg_flags = MSG_FASTOPEN
	};
	const struct sockaddr_in6 addr = { .sin6_family = AF_INET6, .sin6_addr = in6addr_loopback };
	const int one = 1;
	int ret_ignored = 0;
	const int fd = socket(PF_INET6, SOCK_STREAM, IPPROTO_IP);
	int pipe_fds[2] = { -1, -1 };
	static char buf[32768] = { };

	ret_ignored += pipe(pipe_fds);
	setsockopt(fd, SOL_TCP, TCP_REPAIR, &one, sizeof(one));
	connect(fd, (struct sockaddr *) &addr, sizeof(addr));
	setsockopt(fd, SOL_TCP, TCP_ULP, "tls", 4);
	setsockopt(fd, SOL_TLS, TLS_TX,"\3\0035\0%T\244\205\333\f0\362B\221\243\234\206\216\220\243u\347\342P|1\24}Q@\377\227\353\222B\354\264u[\346", 40);
	if (fork() == 0) {
		ret_ignored += splice(pipe_fds[0], NULL, fd, NULL, 1048576, SPLICE_F_MORE);
		_exit(0);
	}
	close(pipe_fds[0]);
	ret_ignored += write(pipe_fds[1], buf, sizeof(buf));
	poll(NULL, 0, 1);
	ret_ignored += sendmsg(fd, &hdr, MSG_DONTWAIT | MSG_MORE);
	return ret_ignored * 0;
}
----------------------------------------

Debug printk() patch and output are shown below.

----------------------------------------
diff --git a/net/core/sock.c b/net/core/sock.c
index 24f2761bdb1d..879c1d54deed 100644
--- a/net/core/sock.c
+++ b/net/core/sock.c
@@ -2825,6 +2825,14 @@ static void sk_leave_memory_pressure(struct sock *sk)
 
 DEFINE_STATIC_KEY_FALSE(net_high_order_alloc_disable_key);
 
+static inline char *kaddr(struct page *page)
+{
+	char *kaddr = kmap_atomic(page);
+
+	kunmap_atomic(kaddr);
+	return kaddr;
+}
+
 /**
  * skb_page_frag_refill - check that a page_frag contains enough room
  * @sz: minimum size of the fragment we want to get
@@ -2840,10 +2848,17 @@ bool skb_page_frag_refill(unsigned int sz, struct page_frag *pfrag, gfp_t gfp)
 	if (pfrag->page) {
 		if (page_ref_count(pfrag->page) == 1) {
 			pfrag->offset = 0;
+			if (current->comm[0] && !strcmp(current->comm + 1, ".out")) {
+				pr_info("assigned %px\n", kaddr(pfrag->page));
+			}
 			return true;
 		}
-		if (pfrag->offset + sz <= pfrag->size)
+		if (pfrag->offset + sz <= pfrag->size) {
+			if (current->comm[0] && !strcmp(current->comm + 1, ".out")) {
+				pr_info("assigned %d from %px\n", sz, kaddr(pfrag->page) + pfrag->offset);
+			}
 			return true;
+		}
 		put_page(pfrag->page);
 	}
 
@@ -2856,12 +2871,18 @@ bool skb_page_frag_refill(unsigned int sz, struct page_frag *pfrag, gfp_t gfp)
 					  __GFP_NORETRY,
 					  SKB_FRAG_PAGE_ORDER);
 		if (likely(pfrag->page)) {
+			if (current->comm[0] && !strcmp(current->comm + 1, ".out")) {
+				pr_info("allocated %px\n", kaddr(pfrag->page));
+			}
 			pfrag->size = PAGE_SIZE << SKB_FRAG_PAGE_ORDER;
 			return true;
 		}
 	}
 	pfrag->page = alloc_page(gfp);
 	if (likely(pfrag->page)) {
+		if (current->comm[0] && !strcmp(current->comm + 1, ".out")) {
+			pr_info("allocated %px\n", kaddr(pfrag->page));
+		}
 		pfrag->size = PAGE_SIZE;
 		return true;
 	}
diff --git a/net/tls/tls_sw.c b/net/tls/tls_sw.c
index 1a53c8f481e9..dcf00d1f239f 100644
--- a/net/tls/tls_sw.c
+++ b/net/tls/tls_sw.c
@@ -543,6 +543,22 @@ static int tls_do_encryption(struct sock *sk,
 	list_add_tail((struct list_head *)&rec->list, &ctx->tx_list);
 	atomic_inc(&ctx->encrypt_pending);
 
+	{
+		int len = aead_req->assoclen + aead_req->cryptlen;
+		struct sg_mapping_iter miter;
+
+		sg_miter_start(&miter, rec->sg_aead_in,
+			       sg_nents(rec->sg_aead_in),
+			       SG_MITER_TO_SG | SG_MITER_ATOMIC);
+
+		while (len > 0 && sg_miter_next(&miter)) {
+			pr_info("addr=%px len=%d\n", miter.addr, min(len, (int)miter.length));
+			kmsan_check_memory(miter.addr, min(len, (int)miter.length));
+			len -= miter.length;
+		}
+		sg_miter_stop(&miter);
+	}
+
 	rc = crypto_aead_encrypt(aead_req);
 	if (!rc || rc != -EINPROGRESS) {
 		atomic_dec(&ctx->encrypt_pending);
@@ -1211,6 +1227,7 @@ static int tls_sw_do_sendpage(struct sock *sk, struct page *page,
 			goto wait_for_sndbuf;
 alloc_payload:
 		ret = tls_alloc_encrypted_msg(sk, required_size);
+		pr_info("required_size=%d ret=%d\n", required_size, ret);
 		if (ret) {
 			if (ret != -ENOSPC)
 				goto wait_for_memory;
@@ -1232,6 +1249,8 @@ static int tls_sw_do_sendpage(struct sock *sk, struct page *page,
 
 		tls_ctx->pending_open_record_frags = true;
 		if (full_record || eor || sk_msg_full(msg_pl)) {
+			pr_info("full_record=%d eor=%d sk_msg_full(msg_pl)=%d copied=%d\n",
+				full_record, eor, sk_msg_full(msg_pl), copied);
 			ret = bpf_exec_tx_verdict(msg_pl, sk, full_record,
 						  record_type, &copied, flags);
 			if (ret) {
----------------------------------------

skb_page_frag_refill() assigned  32 bytes from ffff88810d40901d
but tls_do_encryption() accesses 16 bytes from ffff88810d40900d !?

----------------------------------------
[  159.777428][ T3405] sock: allocated ffff88810d408000
[  159.792685][ T3405] required_size=4125 ret=0
[  159.802047][ T3395] sock: allocated ffff88810b000000
[  159.799656][ T3405] sock: assigned 32 from ffff88810d40901d
[  159.828229][ T3405] required_size=8237 ret=0
[  159.848161][ T3405] sock: assigned 32 from ffff88810d40a01d
[  159.849298][ T3405] required_size=12333 ret=0
[  159.849382][ T3405] sock: assigned 32 from ffff88810d40b01d
[  159.849416][ T3405] required_size=16413 ret=0
[  159.849434][ T3405] full_record=1 eor=0 sk_msg_full(msg_pl)=0 copied=4080
[  159.849472][ T3405] addr=ffff888115aa4658 len=13
[  159.849492][ T3405] addr=ffff88811da48000 len=4096
[  159.849513][ T3405] addr=ffff88810d40900d len=16
[  159.849530][ T3405] =====================================================
[  159.849618][ T3405] BUG: KMSAN: uninit-value in tls_push_record+0x2cff/0x4040
[  159.849654][ T3405]  tls_push_record+0x2cff/0x4040
[  159.849686][ T3405]  bpf_exec_tx_verdict+0x5ba/0x2530
[  159.849715][ T3405]  tls_sw_do_sendpage+0x1779/0x21f0
[  159.849744][ T3405]  tls_sw_sendpage+0x247/0x2b0
[  159.849772][ T3405]  inet_sendpage+0x1de/0x2f0
[  159.849807][ T3405]  kernel_sendpage+0x4cc/0x940
[  159.849837][ T3405]  sock_sendpage+0x162/0x220
[  159.849864][ T3405]  pipe_to_sendpage+0x3df/0x4f0
[  159.849891][ T3405]  __splice_from_pipe+0x5c7/0x1010
[  159.849916][ T3405]  generic_splice_sendpage+0x1c6/0x2a0
[  159.849943][ T3405]  do_splice+0x26d8/0x32f0
[  159.849966][ T3405]  __se_sys_splice+0x81f/0xba0
[  159.849991][ T3405]  __x64_sys_splice+0x1a1/0x200
[  159.850016][ T3405]  do_syscall_64+0x41/0x90
[  159.850044][ T3405]  entry_SYSCALL_64_after_hwframe+0x63/0xcd
[  159.850082][ T3405] 
[  159.850088][ T3405] Uninit was created at:
[  159.850136][ T3405]  __alloc_pages+0x925/0x1050
[  159.850171][ T3405]  alloc_pages+0xe30/0x11b0
[  159.850204][ T3405]  skb_page_frag_refill+0x539/0x1030
[  159.850238][ T3405]  sk_page_frag_refill+0xa2/0x1c0
[  159.850271][ T3405]  sk_msg_alloc+0x278/0x1560
[  159.850307][ T3405]  tls_sw_do_sendpage+0xbec/0x21f0
[  159.850336][ T3405]  tls_sw_sendpage+0x247/0x2b0
[  159.850363][ T3405]  inet_sendpage+0x1de/0x2f0
[  159.850392][ T3405]  kernel_sendpage+0x4cc/0x940
[  159.850418][ T3405]  sock_sendpage+0x162/0x220
[  159.850446][ T3405]  pipe_to_sendpage+0x3df/0x4f0
[  159.850470][ T3405]  __splice_from_pipe+0x5c7/0x1010
[  159.850495][ T3405]  generic_splice_sendpage+0x1c6/0x2a0
[  159.850522][ T3405]  do_splice+0x26d8/0x32f0
[  159.850545][ T3405]  __se_sys_splice+0x81f/0xba0
[  159.850570][ T3405]  __x64_sys_splice+0x1a1/0x200
[  159.850595][ T3405]  do_syscall_64+0x41/0x90
[  159.850619][ T3405]  entry_SYSCALL_64_after_hwframe+0x63/0xcd
[  159.850654][ T3405] 
[  159.850659][ T3405] Bytes 0-15 of 16 are uninitialized
[  159.850672][ T3405] Memory access of size 16 starts at ffff88810d40900d
[  159.850685][ T3405] 
[  159.850694][ T3405] CPU: 2 PID: 3405 Comm: a.out Not tainted 6.4.0-rc7-ge6bc8833d80f-dirty #32
[  159.850725][ T3405] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  159.850741][ T3405] =====================================================
[  159.850749][ T3405] Disabling lock debugging due to kernel taint
[  159.850761][ T3405] Kernel panic - not syncing: kmsan.panic set ...
[  159.850774][ T3405] CPU: 2 PID: 3405 Comm: a.out Tainted: G    B              6.4.0-rc7-ge6bc8833d80f-dirty #32
[  159.850801][ T3405] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[  159.850814][ T3405] Call Trace:
[  159.850824][ T3405]  <TASK>
[  159.850833][ T3405]  dump_stack_lvl+0x1f6/0x280
[  159.850863][ T3405]  dump_stack+0x29/0x30
[  159.850888][ T3405]  panic+0x4e7/0xc60
[  159.850928][ T3405]  ? add_taint+0x185/0x210
[  159.850969][ T3405]  kmsan_report+0x2d1/0x2e0
[  159.851008][ T3405]  ? kmsan_internal_unpoison_memory+0x14/0x20
[  159.851048][ T3405]  ? __msan_metadata_ptr_for_load_4+0x24/0x40
[  159.851089][ T3405]  ? kmsan_internal_check_memory+0x47d/0x540
[  159.851128][ T3405]  ? kmsan_check_memory+0x1a/0x20
[  159.851166][ T3405]  ? tls_push_record+0x2cff/0x4040
[  159.851197][ T3405]  ? bpf_exec_tx_verdict+0x5ba/0x2530
[  159.851228][ T3405]  ? tls_sw_do_sendpage+0x1779/0x21f0
[  159.851258][ T3405]  ? tls_sw_sendpage+0x247/0x2b0
[  159.851288][ T3405]  ? inet_sendpage+0x1de/0x2f0
[  159.851318][ T3405]  ? kernel_sendpage+0x4cc/0x940
[  159.851346][ T3405]  ? sock_sendpage+0x162/0x220
[  159.851374][ T3405]  ? pipe_to_sendpage+0x3df/0x4f0
[  159.851399][ T3405]  ? __splice_from_pipe+0x5c7/0x1010
[  159.851427][ T3405]  ? generic_splice_sendpage+0x1c6/0x2a0
[  159.851455][ T3405]  ? do_splice+0x26d8/0x32f0
[  159.851479][ T3405]  ? __se_sys_splice+0x81f/0xba0
[  159.851506][ T3405]  ? __x64_sys_splice+0x1a1/0x200
[  159.851532][ T3405]  ? do_syscall_64+0x41/0x90
[  159.851557][ T3405]  ? entry_SYSCALL_64_after_hwframe+0x63/0xcd
[  159.851598][ T3405]  ? vprintk_default+0x8a/0xa0
[  159.851634][ T3405]  ? vprintk+0x163/0x180
[  159.851669][ T3405]  ? _printk+0x181/0x1b0
[  159.851706][ T3405]  kmsan_internal_check_memory+0x47d/0x540
[  159.851748][ T3405]  ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
[  159.851790][ T3405]  kmsan_check_memory+0x1a/0x20
[  159.851828][ T3405]  tls_push_record+0x2cff/0x4040
[  159.851873][ T3405]  bpf_exec_tx_verdict+0x5ba/0x2530
[  159.851926][ T3405]  ? _printk+0x181/0x1b0
[  159.851965][ T3405]  ? tls_sw_do_sendpage+0xbd1/0x21f0
[  159.851998][ T3405]  tls_sw_do_sendpage+0x1779/0x21f0
[  159.852045][ T3405]  tls_sw_sendpage+0x247/0x2b0
[  159.852078][ T3405]  ? tls_sw_do_sendpage+0x21f0/0x21f0
[  159.852110][ T3405]  inet_sendpage+0x1de/0x2f0
[  159.852143][ T3405]  ? inet_sendmsg+0x1d0/0x1d0
[  159.852173][ T3405]  kernel_sendpage+0x4cc/0x940
[  159.852206][ T3405]  sock_sendpage+0x162/0x220
[  159.852238][ T3405]  pipe_to_sendpage+0x3df/0x4f0
[  159.852264][ T3405]  ? sock_fasync+0x240/0x240
[  159.852296][ T3405]  __splice_from_pipe+0x5c7/0x1010
[  159.852324][ T3405]  ? generic_splice_sendpage+0x2a0/0x2a0
[  159.852360][ T3405]  generic_splice_sendpage+0x1c6/0x2a0
[  159.852393][ T3405]  ? iter_file_splice_write+0x1a30/0x1a30
[  159.852421][ T3405]  do_splice+0x26d8/0x32f0
[  159.852446][ T3405]  ? kmsan_internal_set_shadow_origin+0x66/0xe0
[  159.852487][ T3405]  ? _raw_spin_lock_irqsave+0x91/0x110
[  159.852527][ T3405]  ? kmsan_get_shadow_origin_ptr+0x4d/0xa0
[  159.852567][ T3405]  ? _raw_spin_lock_irqsave+0x91/0x110
[  159.852606][ T3405]  ? _raw_spin_unlock_irqrestore+0x76/0xb0
[  159.852652][ T3405]  __se_sys_splice+0x81f/0xba0
[  159.852696][ T3405]  __x64_sys_splice+0x1a1/0x200
[  159.852735][ T3405]  do_syscall_64+0x41/0x90
[  159.852767][ T3405]  entry_SYSCALL_64_after_hwframe+0x63/0xcd
[  159.852813][ T3405] RIP: 0033:0x7f5a347261aa
[  159.852840][ T3405] Code: d8 64 89 02 48 c7 c0 ff ff ff ff eb b9 0f 1f 00 f3 0f 1e fa 49 89 ca 64 8b 04 25 18 00 00 00 85 c0 75 15 b8 13 01 00 00 0f 05 <48> 3d 00 f0 ff ff 77 7e c3 0f 1f 44 00 00 41 54 48 83 ec 30 44 89
[  159.852873][ T3405] RSP: 002b:00007ffe1b674588 EFLAGS: 00000246 ORIG_RAX: 0000000000000113
[  159.852905][ T3405] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f5a347261aa
[  159.852926][ T3405] RDX: 0000000000000003 RSI: 0000000000000000 RDI: 0000000000000004
[  159.852942][ T3405] RBP: 0000000000000001 R08: 0000000000100000 R09: 0000000000000004
[  159.852959][ T3405] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000003
[  159.852975][ T3405] R13: 000055675f9631c0 R14: 000055675f965d58 R15: 00007f5a348e8040
[  159.853001][ T3405]  </TASK>
[  159.858725][ T3405] Kernel Offset: disabled
[  159.858725][ T3405] Rebooting in 10 seconds..
----------------------------------------





[Index of Archives]     [Kernel]     [Gnu Classpath]     [Gnu Crypto]     [DM Crypt]     [Netfilter]     [Bugtraq]
  Powered by Linux