TLS module crash while running SSL record encryption using
klts_send_[file] using crypto accelerator (Nitrox).
Following are the preconditions and steps to reproduce the issue:
Preconditions:
1) Installed 5.3-rc4
2) Nitrox5 card plugin (crypto accelerator)
Steps to reproduce the issue:
1) Installed n5pf.ko (drivers/crypto/cavium/nitrox)
2) Installed tls.ko if not is installed by default (net/tls)
3) Obtained uperf tool from GitHub
3.1) Modified uperf to use tls module by using setsocket.
3.2) Modified uperf tool to support sendfile with SSL.
Test:
1) Ran uperf with 4 threads
2) Each thread sends data using sendfile over SSL protocol.
After a few seconds into the test, kernel crashes because of record
list corruption
[ 270.888952] ------------[ cut here ]------------
[ 270.890450] list_del corruption, ffff91cc3753a800->prev is
LIST_POISON2 (dead000000000122)
[ 270.891194] WARNING: CPU: 1 PID: 7387 at lib/list_debug.c:50
__list_del_entry_valid+0x62/0x90
[ 270.892037] Modules linked in: n5pf(OE) netconsole tls(OE) bonding
intel_rapl_msr intel_rapl_common sb_edac x86_pkg_temp_thermal
intel_powerclamp coretemp kvm_intel kvm iTCO_wdt iTCO_vendor_support
irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel
aesni_intel crypto_simd mei_me cryptd glue_helper ipmi_si sg mei
lpc_ich pcspkr joydev ioatdma i2c_i801 ipmi_devintf ipmi_msghandler
wmi ip_tables xfs libcrc32c sd_mod mgag200 drm_vram_helper ttm
drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm isci
libsas ahci scsi_transport_sas libahci crc32c_intel serio_raw igb
libata ptp pps_core dca i2c_algo_bit dm_mirror dm_region_hash dm_log
dm_mod [last unloaded: nitrox_drv]
[ 270.896836] CPU: 1 PID: 7387 Comm: uperf Kdump: loaded Tainted: G
OE 5.3.0-rc4 #1
[ 270.897711] Hardware name: Supermicro SYS-1027R-N3RF/X9DRW, BIOS
3.0c 03/24/2014
[ 270.898597] RIP: 0010:__list_del_entry_valid+0x62/0x90
[ 270.899478] Code: 00 00 00 c3 48 89 fe 48 89 c2 48 c7 c7 e0 f9 ee
8d e8 b2 cf c8 ff 0f 0b 31 c0 c3 48 89 fe 48 c7 c7 18 fa ee 8d e8 9e
cf c8 ff <0f> 0b 31 c0 c3 48 89 f2 48 89 fe 48 c7 c7 50 fa ee 8d e8 87
cf c8
[ 270.901321] RSP: 0018:ffffb6ea86eb7c20 EFLAGS: 00010282
[ 270.902240] RAX: 0000000000000000 RBX: ffff91cc3753c000 RCX: 0000000000000000
[ 270.903157] RDX: ffff91bc3f867080 RSI: ffff91bc3f857738 RDI: ffff91bc3f857738
[ 270.904074] RBP: ffff91bc36020940 R08: 0000000000000560 R09: 0000000000000000
[ 270.904988] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
[ 270.905902] R13: ffff91cc3753a800 R14: ffff91cc37cc6400 R15: ffff91cc3753a800
[ 270.906809] FS: 00007f454a88d700(0000) GS:ffff91bc3f840000(0000)
knlGS:0000000000000000
[ 270.907715] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 270.908606] CR2: 00007f453c00292c CR3: 000000103554e003 CR4: 00000000001606e0
[ 270.909490] Call Trace:
[ 270.910373] tls_tx_records+0x138/0x1c0 [tls]
[ 270.911262] tls_sw_sendpage+0x3e0/0x420 [tls]
[ 270.912154] inet_sendpage+0x52/0x90
[ 270.913045] ? direct_splice_actor+0x40/0x40
[ 270.913941] kernel_sendpage+0x1a/0x30
[ 270.914831] sock_sendpage+0x20/0x30
[ 270.915714] pipe_to_sendpage+0x62/0x90
[ 270.916592] __splice_from_pipe+0x80/0x180
[ 270.917461] ? direct_splice_actor+0x40/0x40
[ 270.918334] splice_from_pipe+0x5d/0x90
[ 270.919208] direct_splice_actor+0x35/0x40
[ 270.920086] splice_direct_to_actor+0x103/0x230
[ 270.920966] ? generic_pipe_buf_nosteal+0x10/0x10
[ 270.921850] do_splice_direct+0x9a/0xd0
[ 270.922733] do_sendfile+0x1c9/0x3d0
[ 270.923612] __x64_sys_sendfile64+0x5c/0xc0
Observations:
1) This issue is observed after applying "Commit a42055e8d2c3: Add
support for async encryption of records for performance"
2) 5.2.2 kernel exhibits the same issue
Attached is the complete crash log.
Bugzilla: https://bugzilla.kernel.org/show_bug.cgi?id=204669
linux-crypto original post:
https://marc.info/?l=linux-crypto-vger&m=156700690108854&w=2
After adding custom profiling around lock_sock/release_sock as well as
getting backtraces of the call stack at and around the time of the
crash/race-condition, it seems like using the socket lock is not the
best way to synchronize write access to tls_tx_records, especially
when the socket lock can get released under tcp memory pressure situation.
One potential way for race condition to appear:
When under tcp memory pressure, Thread 1 takes the following code path:
do_sendfile ---> ... ---> .... ---> tls_sw_sendpage --->
tls_sw_do_sendpage ---> tls_tx_records ---> tls_push_sg --->
do_tcp_sendpages ---> sk_stream_wait_memory ---> sk_wait_event
sk_wait_event releases the socket lock and sleeps waiting for memory:
#define sk_wait_event(__sk, __timeo, __condition, __wait) \
({ int __rc; \
release_sock(__sk); \
__rc = __condition; \
if (!__rc) { \
*(__timeo) = wait_woken(__wait, \
TASK_INTERRUPTIBLE, \
*(__timeo)); \
} \
sched_annotate_sleep(); \
lock_sock(__sk); \
__rc = __condition; \
__rc; \
})
Thread 2 code path:
tx_work_handler ---> tls_tx_records
Thread 2 is able to obtain the socket lock and go through the
transmission of the ctx->tx_list, deleting the sent ones (as in the
for loop below).
int tls_tx_records(struct sock *sk, int flags)
{
....
....
....
....
list_for_each_entry_safe(rec, tmp, &ctx->tx_list, list) {
if (READ_ONCE(rec->tx_ready)) {
if (flags == -1)
tx_flags = rec->tx_flags;
else
tx_flags = flags;
msg_en = &rec->msg_encrypted;
rc = tls_push_sg(sk, tls_ctx,
&msg_en->sg.data[msg_en->sg.curr],
0, tx_flags);
if (rc)
goto tx_err;
list_del(&rec->list); // **** crash location ****
sk_msg_free(sk, &rec->msg_plaintext);
kfree(rec);
} else {
break;
}
}
....
....
....
....
}
When Thread 1 wakes up from tls_push_sg call and attempts list_del on
previously grabbed record which was sent and deleted by Thread 2, it
causes the crash.
To fix this race, a flag or bool inside of ctx can be used to
synchronize access to tls_tx_records.
[ 270.888952] ------------[ cut here ]------------
[ 270.890450] list_del corruption, ffff91cc3753a800->prev is LIST_POISON2
(dead000000000122)
[ 270.891194] WARNING: CPU: 1 PID: 7387 at lib/list_debug.c:50
__list_del_entry_valid+0x62/0x90
[ 270.892037] Modules linked in: n5pf(OE) netconsole tls(OE) bonding
intel_rapl_msr intel_rapl_common sb_edac x86_pkg_temp_thermal intel_powerclamp
coretemp kvm_intel kvm iTCO_wdt iTCO_vendor_support irqbypass crct10dif_pclmul
crc32_pclmul ghash_clmulni_intel aesni_intel crypto_simd mei_me cryptd
glue_helper ipmi_si sg mei lpc_ich pcspkr joydev ioatdma i2c_i801 ipmi_devintf
ipmi_msghandler wmi ip_tables xfs libcrc32c sd_mod mgag200 drm_vram_helper ttm
drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm isci libsas
ahci scsi_transport_sas libahci crc32c_intel serio_raw igb libata ptp pps_core
dca i2c_algo_bit dm_mirror dm_region_hash dm_log dm_mod [last unloaded:
nitrox_drv]
[ 270.896836] CPU: 1 PID: 7387 Comm: uperf Kdump: loaded Tainted: G
OE 5.3.0-rc4 #1
[ 270.897711] Hardware name: Supermicro SYS-1027R-N3RF/X9DRW, BIOS 3.0c
03/24/2014
[ 270.898597] RIP: 0010:__list_del_entry_valid+0x62/0x90
[ 270.899478] Code: 00 00 00 c3 48 89 fe 48 89 c2 48 c7 c7 e0 f9 ee 8d e8 b2
cf c8 ff 0f 0b 31 c0 c3 48 89 fe 48 c7 c7 18 fa ee 8d e8 9e cf c8 ff <0f> 0b 31
c0 c3 48 89 f2 48 89 fe 48 c7 c7 50 fa ee 8d e8 87 cf c8
[ 270.901321] RSP: 0018:ffffb6ea86eb7c20 EFLAGS: 00010282
[ 270.902240] RAX: 0000000000000000 RBX: ffff91cc3753c000 RCX: 0000000000000000
[ 270.903157] RDX: ffff91bc3f867080 RSI: ffff91bc3f857738 RDI: ffff91bc3f857738
[ 270.904074] RBP: ffff91bc36020940 R08: 0000000000000560 R09: 0000000000000000
[ 270.904988] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
[ 270.905902] R13: ffff91cc3753a800 R14: ffff91cc37cc6400 R15: ffff91cc3753a800
[ 270.906809] FS: 00007f454a88d700(0000) GS:ffff91bc3f840000(0000)
knlGS:0000000000000000
[ 270.907715] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 270.908606] CR2: 00007f453c00292c CR3: 000000103554e003 CR4: 00000000001606e0
[ 270.909490] Call Trace:
[ 270.910373] tls_tx_records+0x138/0x1c0 [tls]
[ 270.911262] tls_sw_sendpage+0x3e0/0x420 [tls]
[ 270.912154] inet_sendpage+0x52/0x90
[ 270.913045] ? direct_splice_actor+0x40/0x40
[ 270.913941] kernel_sendpage+0x1a/0x30
[ 270.914831] sock_sendpage+0x20/0x30
[ 270.915714] pipe_to_sendpage+0x62/0x90
[ 270.916592] __splice_from_pipe+0x80/0x180
[ 270.917461] ? direct_splice_actor+0x40/0x40
[ 270.918334] splice_from_pipe+0x5d/0x90
[ 270.919208] direct_splice_actor+0x35/0x40
[ 270.920086] splice_direct_to_actor+0x103/0x230
[ 270.920966] ? generic_pipe_buf_nosteal+0x10/0x10
[ 270.921850] do_splice_direct+0x9a/0xd0
[ 270.922733] do_sendfile+0x1c9/0x3d0
[ 270.923612] __x64_sys_sendfile64+0x5c/0xc0
[ 270.924485] do_syscall_64+0x5b/0x1d0
[ 270.925344] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 270.926188] RIP: 0033:0x7f454c9bf6ba
[ 270.927010] Code: 31 c0 5b c3 0f 1f 40 00 48 89 da 4c 89 ce 44 89 c7 5b e9
09 fe ff ff 66 0f 1f 84 00 00 00 00 00 49 89 ca b8 28 00 00 00 0f 05 <48> 3d 01
f0 ff ff 73 01 c3 48 8b 0d 86 27 2d 00 f7 d8 64 89 01 48
[ 270.928710] RSP: 002b:00007f454a88cd08 EFLAGS: 00000246 ORIG_RAX:
0000000000000028
[ 270.929573] RAX: ffffffffffffffda RBX: 0000000002025460 RCX: 00007f454c9bf6ba
[ 270.930433] RDX: 00007f454a88cd18 RSI: 0000000000000005 RDI: 000000000000000a
[ 270.931294] RBP: 000000000000000a R08: 00007f454cc920ec R09: 00007f454cc92140
[ 270.932146] R10: 0000000000001000 R11: 0000000000000246 R12: 0000000000000000
[ 270.932988] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000002030788
[ 270.933809] ---[ end trace 4ee70802e847a9de ]---
[ 270.934624] ------------[ cut here ]------------
[ 270.935957] list_del corruption, ffff91cc3753c000->prev is LIST_POISON2
(dead000000000122)
[ 270.937381] WARNING: CPU: 1 PID: 7387 at lib/list_debug.c:50
__list_del_entry_valid+0x62/0x90
[ 270.938384] Modules linked in: n5pf(OE) netconsole tls(OE) bonding
intel_rapl_msr intel_rapl_common sb_edac x86_pkg_temp_thermal intel_powerclamp
coretemp kvm_intel kvm iTCO_wdt iTCO_vendor_support irqbypass crct10dif_pclmul
crc32_pclmul ghash_clmulni_intel aesni_intel crypto_simd mei_me cryptd
glue_helper ipmi_si sg mei lpc_ich pcspkr joydev ioatdma i2c_i801 ipmi_devintf
ipmi_msghandler wmi ip_tables xfs libcrc32c sd_mod mgag200 drm_vram_helper ttm
drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm isci libsas
ahci scsi_transport_sas libahci crc32c_intel serio_raw igb libata ptp pps_core
dca i2c_algo_bit dm_mirror dm_region_hash dm_log dm_mod [last unloaded:
nitrox_drv]
[ 270.943119] CPU: 1 PID: 7387 Comm: uperf Kdump: loaded Tainted: G W
OE 5.3.0-rc4 #1
[ 270.943920] Hardware name: Supermicro SYS-1027R-N3RF/X9DRW, BIOS 3.0c
03/24/2014
[ 270.944725] RIP: 0010:__list_del_entry_valid+0x62/0x90
[ 270.945522] Code: 00 00 00 c3 48 89 fe 48 89 c2 48 c7 c7 e0 f9 ee 8d e8 b2
cf c8 ff 0f 0b 31 c0 c3 48 89 fe 48 c7 c7 18 fa ee 8d e8 9e cf c8 ff <0f> 0b 31
c0 c3 48 89 f2 48 89 fe 48 c7 c7 50 fa ee 8d e8 87 cf c8
[ 270.947193] RSP: 0018:ffffb6ea86eb7c20 EFLAGS: 00010282
[ 270.948037] RAX: 0000000000000000 RBX: ffff91cc3753a800 RCX: 0000000000000000
[ 270.948882] RDX: ffff91bc3f867080 RSI: ffff91bc3f857738 RDI: ffff91bc3f857738
[ 270.949723] RBP: ffff91bc36020940 R08: 000000000000058d R09: 0000000000000000
[ 270.950562] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
[ 270.951387] R13: ffff91cc3753c000 R14: ffff91cc37cc6400 R15: ffff91cc3753c000
[ 270.952220] FS: 00007f454a88d700(0000) GS:ffff91bc3f840000(0000)
knlGS:0000000000000000
[ 270.953065] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 270.953914] CR2: 00007f453c00292c CR3: 000000103554e003 CR4: 00000000001606e0
[ 270.954777] Call Trace:
[ 270.955636] tls_tx_records+0x138/0x1c0 [tls]
[ 270.956499] tls_sw_sendpage+0x3e0/0x420 [tls]
[ 270.957366] inet_sendpage+0x52/0x90
[ 270.958232] ? direct_splice_actor+0x40/0x40
[ 270.959101] kernel_sendpage+0x1a/0x30
[ 270.959967] sock_sendpage+0x20/0x30
[ 270.960830] pipe_to_sendpage+0x62/0x90
[ 270.961693] __splice_from_pipe+0x80/0x180
[ 270.962556] ? direct_splice_actor+0x40/0x40
[ 270.963413] splice_from_pipe+0x5d/0x90
[ 270.964274] direct_splice_actor+0x35/0x40
[ 270.965136] splice_direct_to_actor+0x103/0x230
[ 270.966001] ? generic_pipe_buf_nosteal+0x10/0x10
[ 270.966867] do_splice_direct+0x9a/0xd0
[ 270.967727] do_sendfile+0x1c9/0x3d0
[ 270.968565] __x64_sys_sendfile64+0x5c/0xc0
[ 270.969380] do_syscall_64+0x5b/0x1d0
[ 270.970185] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 270.970985] RIP: 0033:0x7f454c9bf6ba
[ 270.971778] Code: 31 c0 5b c3 0f 1f 40 00 48 89 da 4c 89 ce 44 89 c7 5b e9
09 fe ff ff 66 0f 1f 84 00 00 00 00 00 49 89 ca b8 28 00 00 00 0f 05 <48> 3d 01
f0 ff ff 73 01 c3 48 8b 0d 86 27 2d 00 f7 d8 64 89 01 48
[ 270.973438] RSP: 002b:00007f454a88cd08 EFLAGS: 00000246 ORIG_RAX:
0000000000000028
[ 270.974293] RAX: ffffffffffffffda RBX: 0000000002025460 RCX: 00007f454c9bf6ba
[ 270.975148] RDX: 00007f454a88cd18 RSI: 0000000000000005 RDI: 000000000000000a
[ 270.976009] RBP: 000000000000000a R08: 00007f454cc920ec R09: 00007f454cc92140
[ 270.976860] R10: 0000000000001000 R11: 0000000000000246 R12: 0000000000000000
[ 270.977699] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000002030788
[ 270.978514] ---[ end trace 4ee70802e847a9df ]---
[ 270.979330] BUG: unable to handle page fault for address: ffff91d383e05784
[ 270.980749] #PF: supervisor read access in kernel mode
[ 270.981820] #PF: error_code(0x0000) - not-present page
[ 270.982571] PGD 1032e01067 P4D 1032e01067 PUD 0
[ 270.983303] Oops: 0000 [#1] SMP PTI
[ 270.984020] CPU: 1 PID: 7387 Comm: uperf Kdump: loaded Tainted: G W
OE 5.3.0-rc4 #1
[ 270.984748] Hardware name: Supermicro SYS-1027R-N3RF/X9DRW, BIOS 3.0c
03/24/2014
[ 270.985473] RIP: 0010:tls_push_sg+0x27/0x190 [tls]
[ 270.986184] Code: 00 00 00 0f 1f 44 00 00 41 57 44 0f b7 d1 41 56 41 55 49
89 d5 41 54 45 89 c4 41 81 cc 00 00 02 00 55 48 89 fd 53 48 83 ec 10 <44> 8b 4a
0c 48 89 74 24 08 44 89 44 24 04 45 89 ce 45 29 d6 44 03
[ 270.987631] RSP: 0018:ffffb6ea86eb7be0 EFLAGS: 00010282
[ 270.988350] RAX: 000000074c8caca0 RBX: ffff91cc3753b800 RCX: 0000000000000000
[ 270.989081] RDX: ffff91d383e05778 RSI: ffff91cc37cc6400 RDI: ffff91bc36020940
[ 270.989813] RBP: ffff91bc36020940 R08: 0000000000000000 R09: 0000000000000000
[ 270.990548] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000020000
[ 270.991272] R13: ffff91d383e05778 R14: ffff91cc37cc6400 R15: ffff91cc3753a800
[ 270.991999] FS: 00007f454a88d700(0000) GS:ffff91bc3f840000(0000)
knlGS:0000000000000000
[ 270.992727] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 270.993448] CR2: ffff91d383e05784 CR3: 000000103554e003 CR4: 00000000001606e0
[ 270.994177] Call Trace:
[ 270.994905] tls_tx_records+0x128/0x1c0 [tls]
[ 270.995638] tls_sw_sendpage+0x3e0/0x420 [tls]
[ 270.996365] inet_sendpage+0x52/0x90
[ 270.997095] ? direct_splice_actor+0x40/0x40
[ 270.997826] kernel_sendpage+0x1a/0x30
[ 270.998555] sock_sendpage+0x20/0x30
[ 270.999281] pipe_to_sendpage+0x62/0x90
[ 271.000010] __splice_from_pipe+0x80/0x180
[ 271.000740] ? direct_splice_actor+0x40/0x40
[ 271.001467] splice_from_pipe+0x5d/0x90
[ 271.002199] direct_splice_actor+0x35/0x40
[ 271.002930] splice_direct_to_actor+0x103/0x230
[ 271.003661] ? generic_pipe_buf_nosteal+0x10/0x10
[ 271.004387] do_splice_direct+0x9a/0xd0
[ 271.005118] do_sendfile+0x1c9/0x3d0
[ 271.005849] __x64_sys_sendfile64+0x5c/0xc0
[ 271.006579] do_syscall_64+0x5b/0x1d0
[ 271.007301] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 271.008031] RIP: 0033:0x7f454c9bf6ba
[ 271.008737] Code: 31 c0 5b c3 0f 1f 40 00 48 89 da 4c 89 ce 44 89 c7 5b e9
09 fe ff ff 66 0f 1f 84 00 00 00 00 00 49 89 ca b8 28 00 00 00 0f 05 <48> 3d 01
f0 ff ff 73 01 c3 48 8b 0d 86 27 2d 00 f7 d8 64 89 01 48
[ 271.010187] RSP: 002b:00007f454a88cd08 EFLAGS: 00000246 ORIG_RAX:
0000000000000028
[ 271.010915] RAX: ffffffffffffffda RBX: 0000000002025460 RCX: 00007f454c9bf6ba
[ 271.011648] RDX: 00007f454a88cd18 RSI: 0000000000000005 RDI: 000000000000000a
[ 271.012374] RBP: 000000000000000a R08: 00007f454cc920ec R09: 00007f454cc92140
[ 271.013109] R10: 0000000000001000 R11: 0000000000000246 R12: 0000000000000000
[ 271.013848] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000002030788
[ 271.014577] Modules linked in: n5pf(OE) netconsole tls(OE) bonding
intel_rapl_msr intel_rapl_common sb_edac x86_pkg_temp_thermal intel_powerclamp
coretemp kvm_intel kvm iTCO_wdt iTCO_vendor_support irqbypass crct10dif_pclmul
crc32_pclmul ghash_clmulni_intel aesni_intel crypto_simd mei_me cryptd
glue_helper ipmi_si sg mei lpc_ich pcspkr joydev ioatdma i2c_i801 ipmi_devintf
ipmi_msghandler wmi ip_tables xfs libcrc32c sd_mod mgag200 drm_vram_helper ttm
drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm isci libsas
ahci scsi_transport_sas libahci crc32c_intel serio_raw igb libata ptp pps_core
dca i2c_algo_bit dm_mirror dm_region_hash dm_log dm_mod [last unloaded:
nitrox_drv]
[ 271.019344] CR2: ffff91d383e05784
