Skip to content

kmem_cache_destroy ttls_hs_cache: Slab cache still has objects #1277

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
krizhanovsky opened this issue Jun 27, 2019 · 4 comments · Fixed by #1292
Closed

kmem_cache_destroy ttls_hs_cache: Slab cache still has objects #1277

krizhanovsky opened this issue Jun 27, 2019 · 4 comments · Fixed by #1292
Assignees
@krizhanovsky @i-rinat
Labels
bug crucial
Milestone
0.7 - HTTP/2

Comments

@krizhanovsky
Copy link
Contributor

krizhanovsky commented Jun 27, 2019 •
edited
Loading

Just got following crash during debugging of #737 . I saw the bug only twice while I was running the same tests for a while, so it seems the bug is hard to reproduce. Tempesta state and configuration:

root@debian:~/tempesta# git log |head -1
commit 6bb569743aa5c16fd977bf38b54df260fb78a5de
root@debian:~/tempesta# cat etc/tempesta_fw.conf
listen 443 proto=https;

sched ratio;
server 127.0.0.1:8080;

vhost default {
	proxy_pass default;
}

cache 0;

tls_certificate /root/tempesta/etc/tfw-root.crt;
tls_certificate_key /root/tempesta/etc/tfw-root.key;

Crash dump:

[ 3891.696495] [tempesta fw]     tfw_mod_unregister: tls
[ 3891.700477] [tempesta fw]     tfw_mod_unregister: vhost
[ 3891.704036] [tempesta fw]     tfw_mod_unregister: apm
[ 3891.720830] [tdb] Shutdown Tempesta DB
[ 3891.736201] kmem_cache_destroy ttls_hs_cache: Slab cache still has objects
[ 3891.741008] CPU: 1 PID: 1103 Comm: rmmod Tainted: G           O    4.14.32-kdump+ #142
[ 3891.744438] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-2.fc30 04/01/2014
[ 3891.747282] Call Trace:
[ 3891.748304]  dump_stack+0x46/0x5a
[ 3891.749520]  kmem_cache_destroy+0x1c3/0x1d0
[ 3891.751109]  ttls_exit+0x1e/0x60 [tempesta_tls]
[ 3891.752549]  SyS_delete_module+0x19a/0x250
[ 3891.753837]  do_syscall_64+0x61/0x110
[ 3891.755021]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[ 3891.756433] RIP: 0033:0x7ff11006ffd7
[ 3891.757656] RSP: 002b:00007ffdc3516168 EFLAGS: 00000206 ORIG_RAX: 00000000000000b0
[ 3891.759205] RAX: ffffffffffffffda RBX: 00007ffdc35161b8 RCX: 00007ff11006ffd7
[ 3891.760561] RDX: 000000000000000a RSI: 0000000000000800 RDI: 00005608cb3e1258
[ 3891.761852] RBP: 00005608cb3e11f0 R08: 00007ffdc35150e1 R09: 000000000000000a
[ 3891.763136] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffdc3516380
[ 3891.764440] R13: 00007ffdc3517e28 R14: 0000000000000000 R15: 00005608cb3e11f0
[ 3904.012797] device lo left promiscuous mode
[ 3958.117415] BUG: unable to handle kernel paging request at ffffffffc0403520
[ 3958.120252] IP: 0xffffffffc0403520
[ 3958.121510] PGD 72c0c067 P4D 72c0c067 PUD 72c0e067 PMD 3fc51067 PTE 0
[ 3958.123300] Oops: 0010 [#1] SMP PTI
[ 3958.124541] Modules linked in: binfmt_misc bochs_drm ttm drm_kms_helper drm crct10dif_pclmul ppdev fb_sys_fops pcspkr parport_pc syscopyarea sysfillrect sysimgblt serio_raw button sg parport ip_tables x_tables ext4 crc16 mbcache jbd2 fscrypto sr_mod cdrom sd_mod ata_generic ata_piix libata psmouse scsi_mod e1000 i2c_piix4 [last unloaded: tempesta_lib]
[ 3958.131759] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G           O    4.14.32-kdump+ #142
[ 3958.133670] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-2.fc30 04/01/2014
[ 3958.135406] task: ffff890173ff30c0 task.stack: ffff890174454000
[ 3958.136708] RIP: 0010:0xffffffffc0403520
[ 3958.137878] RSP: 0018:ffff89017fd03eb0 EFLAGS: 00010206
[ 3958.139231] RAX: 0000000000000000 RBX: 0000000000000001 RCX: ffff89017b14ca50
[ 3958.140616] RDX: ffff89017b14c788 RSI: ffffffffc0403520 RDI: ffff89017b14c788
[ 3958.142567] RBP: 0000000000000100 R08: ffff89017fd19e80 R09: ffff89017fd03ef0
[ 3958.144152] R10: ffff89017fd196b0 R11: ffffffffbd211ae8 R12: ffff89017b14ca50
[ 3958.145520] R13: ffffffffc0403520 R14: ffff89017b14c788 R15: 0000000000000000
[ 3958.146863] FS:  0000000000000000(0000) GS:ffff89017fd00000(0000) knlGS:0000000000000000
[ 3958.148329] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 3958.149860] CR2: ffffffffc0403520 CR3: 0000000072c0a005 CR4: 00000000003606e0
[ 3958.151316] Call Trace:
[ 3958.152153]  <IRQ>
[ 3958.152900]  ? call_timer_fn+0x2b/0x120
[ 3958.153937]  ? run_timer_softirq+0x1c5/0x3f0
[ 3958.154970]  ? tick_sched_do_timer+0x40/0x40
[ 3958.155995]  ? timerqueue_add+0x54/0x80
[ 3958.156977]  ? enqueue_hrtimer+0x33/0x80
[ 3958.158014]  ? __do_softirq+0x104/0x297
[ 3958.159139]  ? irq_exit+0xa3/0xb0
[ 3958.160348]  ? smp_apic_timer_interrupt+0x6b/0x120
[ 3958.162648]  ? apic_timer_interrupt+0x7a/0x80
[ 3958.164129]  </IRQ>
[ 3958.165354]  ? __sched_text_end+0x3/0x3
[ 3958.166792]  ? default_idle+0x12/0xf0
[ 3958.168178]  ? do_idle+0x156/0x1b0
[ 3958.169560]  ? cpu_startup_entry+0x6a/0x70
[ 3958.171116]  ? start_secondary+0x188/0x1b0
[ 3958.172668]  ? secondary_startup_64+0xa5/0xb0
[ 3958.174144] Code:  Bad RIP value.
[ 3958.175443] RIP: 0xffffffffc0403520 RSP: ffff89017fd03eb0
[ 3958.177075] CR2: ffffffffc0403520
[ 3958.178351] ---[ end trace a3f11b8a3db3bcb2 ]---
[ 3958.179887] Kernel panic - not syncing: Fatal exception in interrupt
[ 3958.181730] Kernel Offset: 0x3b600000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[ 3958.183872] Rebooting in 60 seconds..
@krizhanovsky krizhanovsky added this to the 0.7 HTTP/2 milestone Jun 27, 2019
@krizhanovsky
Copy link
Contributor Author

Note that I'm debugging issues with TLS handshakes, partial transmission of ClientHello in particular, so probably the issue is linked with early (failure) return from the handshake operation. Here is debug messages from the handshake - note one more calltrace:

[ 3881.316486] [tempesta fw]   new client: cli=ffff89016fc05018
[ 3881.317952] [tempesta fw]   client address: 127.0.0.1
[ 3881.319314] [tempesta fw]     client ffff89016fc05018, users=1
[ 3881.320776] [tempesta fw]       new client socket: sk=ffff89012fde6bc0, state=1
[ 3881.322708] [tempesta fw]   client was found in tdb
[ 3881.324017] [tempesta fw]     client ffff89016fc05018, users=2
[ 3881.325479] [tempesta fw]     tfw_http_conn_init: conn=[ffff89017b14c788]
[ 3881.328514] [tempesta fw]       new client socket is accepted: sk=ffff89012fde6bc0, conn=ffff89017b14c788, cli=ffff89016fc05018
[ 3881.337112] [tempesta fw]       GFSM exec fsm 1, state 0x2200
[ 3881.338623] [tempesta tls]       ttls_recv: tls=ffff89017b14cab8 len=238 read=0
[ 3881.340485] [tempesta tls]       input rec: type=22 ver=3:1 msglen=233 read=5 xfrm_ready=0
[ 3881.343152] [tempesta tls]   handshake message: msglen=233 type=1 hslen=229 read=9
[ 3881.345208] [tempesta tls]       handshake message 22 on state 0
[ 3881.347228] [tempesta tls]   server state: 0
[ 3881.348721] [tempesta tls]       enter TLS Server Handshake FSM at state 0x0(TTLS_CLIENT_HELLO)
[ 3881.351213] [tempesta tls]       enter TLS ClientHello FSM at state 0x0(TTLS_CH_HS_VER)
[ 3881.353785] [tempesta tls]       enter TLS ClientHello FSM at state 0x1(TTLS_CH_HS_RND)
[ 3881.355987] [tempesta tls]       dump 'ClientHello: random bytes ' (ptr=ffff89017b117b70, 32 bytes):
[ 3881.358941] [tempesta tls]         00000000: 72 77 7f 40 8f f7 75 aa 21 e1 aa 33 79 36 6b d3  rw.@..u.!..3y6k.
[ 3881.361839] [tempesta tls]         00000010: b7 d2 f8 5a 77 0f 87 d1 fb 90 5f a0 ef 23 5b 34  ...Zw....._..#[4
[ 3881.363920] [tempesta tls]       enter TLS ClientHello FSM at state 0x2(TTLS_CH_HS_SLEN)
[ 3881.365576] [tempesta tls]       ClientHello: Session ID length 0
[ 3881.367255] [tempesta tls]       enter TLS ClientHello FSM at state 0x4(TTLS_CH_HS_CSLEN)
[ 3881.369388] [tempesta tls]       ClientHello: cipher suites length 124
[ 3881.371061] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.372937] [tempesta tls]       ClientHello: cipher suite #0: 0xc02c
[ 3881.374571] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.376502] [tempesta tls]       ClientHello: cipher suite #1: 0xc030
[ 3881.377947] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.379647] [tempesta tls]       ClientHello: cipher suite #2: 0xc02b
[ 3881.381242] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.383018] [tempesta tls]       ClientHello: cipher suite #3: 0xc02f
[ 3881.384491] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.386239] [tempesta tls]       ClientHello: cipher suite #4: 0xcca9
[ 3881.388328] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.390154] [tempesta tls]       ClientHello: cipher suite #5: 0xcca8
[ 3881.391620] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.393177] [tempesta tls]       ClientHello: cipher suite #6: 0xa3
[ 3881.394644] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.396328] [tempesta tls]       ClientHello: cipher suite #7: 0x9f
[ 3881.397583] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.399290] [tempesta tls]       ClientHello: cipher suite #8: 0xa2
[ 3881.400894] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.402633] [tempesta tls]       ClientHello: cipher suite #9: 0x9e
[ 3881.404109] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.406116] [tempesta tls]       ClientHello: cipher suite #10: 0xccaa
[ 3881.407506] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.409127] [tempesta tls]       ClientHello: cipher suite #11: 0xc0af
[ 3881.410700] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.412342] [tempesta tls]       ClientHello: cipher suite #12: 0xc0ad
[ 3881.413639] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.415211] [tempesta tls]       ClientHello: cipher suite #13: 0xc024
[ 3881.418784] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.420819] [tempesta tls]       ClientHello: cipher suite #14: 0xc028
[ 3881.422647] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.424540] [tempesta tls]       ClientHello: cipher suite #15: 0xc00a
[ 3881.426360] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.428290] [tempesta tls]       ClientHello: cipher suite #16: 0xc014
[ 3881.430300] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.432123] [tempesta tls]       ClientHello: cipher suite #17: 0xc0a3
[ 3881.433562] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.435197] [tempesta tls]       ClientHello: cipher suite #18: 0xc09f
[ 3881.436667] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.438168] [tempesta tls]       ClientHello: cipher suite #19: 0x6b
[ 3881.439597] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.441076] [tempesta tls]       ClientHello: cipher suite #20: 0x6a
[ 3881.442678] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.444216] [tempesta tls]       ClientHello: cipher suite #21: 0x39
[ 3881.445614] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.448868] [tempesta tls]       ClientHello: cipher suite #22: 0x38
[ 3881.450577] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.452317] [tempesta tls]       ClientHello: cipher suite #23: 0xc0ae
[ 3881.453739] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.455547] [tempesta tls]       ClientHello: cipher suite #24: 0xc0ac
[ 3881.457138] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.459243] [tempesta tls]       ClientHello: cipher suite #25: 0xc023
[ 3881.461004] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.462874] [tempesta tls]       ClientHello: cipher suite #26: 0xc027
[ 3881.464491] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.466045] [tempesta tls]       ClientHello: cipher suite #27: 0xc009
[ 3881.467374] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.468890] [tempesta tls]       ClientHello: cipher suite #28: 0xc013
[ 3881.470306] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.471776] [tempesta tls]       ClientHello: cipher suite #29: 0xc0a2
[ 3881.473086] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.474664] [tempesta tls]       ClientHello: cipher suite #30: 0xc09e
[ 3881.476279] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.479063] [tempesta tls]       ClientHello: cipher suite #31: 0x67
[ 3881.480592] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.482212] [tempesta tls]       ClientHello: cipher suite #32: 0x40
[ 3881.483536] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.485078] [tempesta tls]       ClientHello: cipher suite #33: 0x33
[ 3881.486511] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.487997] [tempesta tls]       ClientHello: cipher suite #34: 0x32
[ 3881.489620] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.491267] [tempesta tls]       ClientHello: cipher suite #35: 0xc073
[ 3881.492790] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.494469] [tempesta tls]       ClientHello: cipher suite #36: 0xc077
[ 3881.495842] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.497324] [tempesta tls]       ClientHello: cipher suite #37: 0xc072
[ 3881.498662] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.500204] [tempesta tls]       ClientHello: cipher suite #38: 0xc076
[ 3881.501636] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.503127] [tempesta tls]       ClientHello: cipher suite #39: 0xc4
[ 3881.504459] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.506088] [tempesta tls]       ClientHello: cipher suite #40: 0xc3
[ 3881.508941] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.511134] [tempesta tls]       ClientHello: cipher suite #41: 0xbe
[ 3881.512750] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.514595] [tempesta tls]       ClientHello: cipher suite #42: 0xbd
[ 3881.516165] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.517972] [tempesta tls]       ClientHello: cipher suite #43: 0x88
[ 3881.519522] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.521107] [tempesta tls]       ClientHello: cipher suite #44: 0x87
[ 3881.522554] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.524043] [tempesta tls]       ClientHello: cipher suite #45: 0x45
[ 3881.525461] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.527037] [tempesta tls]       ClientHello: cipher suite #46: 0x44
[ 3881.528348] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.529884] [tempesta tls]       ClientHello: cipher suite #47: 0x9d
[ 3881.531180] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.532681] [tempesta tls]       ClientHello: cipher suite #48: 0x9c
[ 3881.534137] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.535665] [tempesta tls]       ClientHello: cipher suite #49: 0xc0a1
[ 3881.538759] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.540921] [tempesta tls]       ClientHello: cipher suite #50: 0xc09d
[ 3881.542686] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.544578] [tempesta tls]       ClientHello: cipher suite #51: 0xc0a0
[ 3881.546291] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.548175] [tempesta tls]       ClientHello: cipher suite #52: 0xc09c
[ 3881.550126] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.551701] [tempesta tls]       ClientHello: cipher suite #53: 0x3d
[ 3881.552969] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.554509] [tempesta tls]       ClientHello: cipher suite #54: 0x3c
[ 3881.555866] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.557309] [tempesta tls]       ClientHello: cipher suite #55: 0x35
[ 3881.558821] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.560492] [tempesta tls]       ClientHello: cipher suite #56: 0x2f
[ 3881.561840] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.563408] [tempesta tls]       ClientHello: cipher suite #57: 0xc0
[ 3881.564668] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.566462] [tempesta tls]       ClientHello: cipher suite #58: 0xba
[ 3881.568464] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.570433] [tempesta tls]       ClientHello: cipher suite #59: 0x84
[ 3881.571916] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.573541] [tempesta tls]       ClientHello: cipher suite #60: 0x41
[ 3881.574925] [tempesta tls]       enter TLS ClientHello FSM at state 0x5(TTLS_CH_HS_CS)
[ 3881.576455] [tempesta tls]       ClientHello: cipher suite #61: 0xff
[ 3881.577764] [tempesta tls]       enter TLS ClientHello FSM at state 0x7(TTLS_CH_HS_COMPN)
[ 3881.579519] [tempesta tls]       ClientHello: compression algorithms length 1
[ 3881.580990] [tempesta tls]       enter TLS ClientHello FSM at state 0x8(TTLS_CH_HS_COMP)
[ 3881.582743] [tempesta tls]       saw NULL compression
[ 3881.583921] [tempesta tls]       enter TLS ClientHello FSM at state 0x9(TTLS_CH_HS_EXTLEN)
[ 3881.585425] [tempesta tls]       ClientHello: extensions length 64
[ 3881.586811] [tempesta tls]       enter TLS ClientHello FSM at state 0xa(TTLS_CH_HS_EXT)
[ 3881.588295] [tempesta tls]       ClientHello: read extension 0xb...
[ 3881.589560] [tempesta tls]       enter TLS ClientHello FSM at state 0xb(TTLS_CH_HS_EXS)
[ 3881.591095] [tempesta tls]       enter TLS ClientHello FSM at state 0xc(TTLS_CH_HS_EX)
[ 3881.593195] [tempesta tls]       ClientHello: read 4 bytes for ext 11
[ 3881.595402] [tempesta tls]   found supported point formats extension
[ 3881.598553] [tempesta tls]   ClientHello: point format selected: 0
[ 3881.599959] [tempesta tls]       enter TLS ClientHello FSM at state 0xa(TTLS_CH_HS_EXT)
[ 3881.601808] [tempesta tls]       ClientHello: read extension 0xa...
[ 3881.603462] [tempesta tls]       enter TLS ClientHello FSM at state 0xb(TTLS_CH_HS_EXS)
[ 3881.605352] [tempesta tls]       enter TLS ClientHello FSM at state 0xc(TTLS_CH_HS_EX)
[ 3881.607239] [tempesta tls]       ClientHello: read 4 bytes for ext 10
[ 3881.609198] [tempesta tls]   found supported elliptic curves extension
[ 3881.610983] [tempesta tls]       set curve secp256r1
[ 3881.612525] [tempesta tls]       enter TLS ClientHello FSM at state 0xa(TTLS_CH_HS_EXT)
[ 3881.614174] [tempesta tls]       ClientHello: read extension 0x23...
[ 3881.615639] [tempesta tls]       enter TLS ClientHello FSM at state 0xb(TTLS_CH_HS_EXS)
[ 3881.617126] [tempesta tls]       enter TLS ClientHello FSM at state 0xc(TTLS_CH_HS_EX)
[ 3881.618605] [tempesta tls]       ClientHello: read 0 bytes for ext 35
[ 3881.619925] [tempesta tls]   found session ticket extension
[ 3881.621085] [tempesta tls]       enter TLS ClientHello FSM at state 0xa(TTLS_CH_HS_EXT)
[ 3881.622574] [tempesta tls]       ClientHello: read extension 0xd...
[ 3881.623985] [tempesta tls]       enter TLS ClientHello FSM at state 0xb(TTLS_CH_HS_EXS)
[ 3881.625433] [tempesta tls]       enter TLS ClientHello FSM at state 0xc(TTLS_CH_HS_EX)
[ 3881.628913] [tempesta tls]       ClientHello: read 32 bytes for ext 13
[ 3881.630618] [tempesta tls]   found signature_algorithms extension
[ 3881.632056] [tempesta tls]   ClientHello: signature_algorithm ext: hash alg 5 not supported
[ 3881.632057] [tempesta tls]   ClientHello: signature_algorithm ext: unknown sig alg encoding 2
[ 3881.635797] [tempesta tls]   ClientHello: signature_algorithm ext: hash alg 5 not supported
[ 3881.635798] [tempesta tls]   ClientHello: signature_algorithm ext: match sig 1 and hash 4
[ 3881.637751] [tempesta tls]   ClientHello: signature_algorithm ext: unknown sig alg encoding 2
[ 3881.641979] [tempesta tls]   ClientHello: signature_algorithm ext: match sig 4 and hash 4
[ 3881.641980] [tempesta tls]   ClientHello: signature_algorithm ext: match sig 1 and hash 3
[ 3881.643852] [tempesta tls]   ClientHello: signature_algorithm ext: unknown sig alg encoding 2
[ 3881.647277] [tempesta tls]   ClientHello: signature_algorithm ext: match sig 4 and hash 3
[ 3881.647278] [tempesta tls]   ClientHello: signature_algorithm ext: hash alg 2 not supported
[ 3881.648721] [tempesta tls]   ClientHello: signature_algorithm ext: unknown sig alg encoding 2
[ 3881.651695] [tempesta tls]   ClientHello: signature_algorithm ext: hash alg 2 not supported
[ 3881.651696] [tempesta tls]   ClientHello: signature_algorithm ext: unknown hash alg encoding 2
[ 3881.654598] [tempesta tls]   ClientHello: signature_algorithm ext: unknown sig alg encoding 2
[ 3881.656445] [tempesta tls]   ClientHello: signature_algorithm ext: unknown hash alg encoding 2
[ 3881.659446] [tempesta tls]       enter TLS ClientHello FSM at state 0xa(TTLS_CH_HS_EXT)
[ 3881.661199] [tempesta tls]       ClientHello: read extension 0x16...
[ 3881.662575] [tempesta tls]       enter TLS ClientHello FSM at state 0xb(TTLS_CH_HS_EXS)
[ 3881.664032] [tempesta tls]       enter TLS ClientHello FSM at state 0xc(TTLS_CH_HS_EX)
[ 3881.665674] [tempesta tls]       ClientHello: read 0 bytes for ext 22
[ 3881.667095] [tempesta tls]   unknown extension found: 22 (ignoring)
[ 3881.668495] [tempesta tls]       enter TLS ClientHello FSM at state 0xa(TTLS_CH_HS_EXT)
[ 3881.670439] [tempesta tls]       ClientHello: read extension 0x17...
[ 3881.672090] [tempesta tls]       enter TLS ClientHello FSM at state 0xb(TTLS_CH_HS_EXS)
[ 3881.673832] [tempesta tls]       Finish TLS ClientHello FSM at state 0xc, ret=-1
[ 3881.675444] [tempesta tls]     update checksum on buf ffff890174a0d2e5 len=233, hash=4
[ 3881.676841] [tempesta tls]       dump 'hash buf ' (ptr=ffff890174a0d2e5, 233 bytes):
[ 3881.678211] [tempesta tls]         00000000: 01 00 00 e5 03 03 72 77 7f 40 8f f7 75 aa 21 e1  ......rw.@..u.!.
[ 3881.680016] [tempesta tls]         00000010: aa 33 79 36 6b d3 b7 d2 f8 5a 77 0f 87 d1 fb 90  .3y6k....Zw.....
[ 3881.681670] [tempesta tls]         00000020: 5f a0 ef 23 5b 34 00 00 7c c0 2c c0 30 c0 2b c0  _..#[4..|.,.0.+.
[ 3881.683241] [tempesta tls]         00000030: 2f cc a9 cc a8 00 a3 00 9f 00 a2 00 9e cc aa c0  /...............
[ 3881.684953] [tempesta tls]         00000040: af c0 ad c0 24 c0 28 c0 0a c0 14 c0 a3 c0 9f 00  ....$.(.........
[ 3881.688453] [tempesta tls]         00000050: 6b 00 6a 00 39 00 38 c0 ae c0 ac c0 23 c0 27 c0  k.j.9.8.....#.'.
[ 3881.690501] [tempesta tls]         00000060: 09 c0 13 c0 a2 c0 9e 00 67 00 40 00 33 00 32 c0  ........g.@.3.2.
[ 3881.692241] [tempesta tls]         00000070: 73 c0 77 c0 72 c0 76 00 c4 00 c3 00 be 00 bd 00  s.w.r.v.........
[ 3881.693955] [tempesta tls]         00000080: 88 00 87 00 45 00 44 00 9d 00 9c c0 a1 c0 9d c0  ....E.D.........
[ 3881.695788] [tempesta tls]         00000090: a0 c0 9c 00 3d 00 3c 00 35 00 2f 00 c0 00 ba 00  ....=.<.5./.....
[ 3881.697896] [tempesta tls]         000000a0: 84 00 41 00 ff 01 00 00 40 00 0b 00 04 03 00 01  ..A.....@.......
[ 3881.700313] [tempesta tls]         000000b0: 02 00 0a 00 04 00 02 00 17 00 23 00 00 00 0d 00  ..........#.....
[ 3881.700313] [tempesta tls]         000000b0: 02 00 0a 00 04 00 02 00 17 00 23 00 00 00 0d 00  ..........#.....
[ 3881.702429] [tempesta tls]         000000c0: 20 00 1e 06 01 06 02 06 03 05 01 05 02 05 03 04   ...............
[ 3881.704478] [tempesta tls]         000000d0: 01 04 02 04 03 03 01 03 02 03 03 02 01 02 02 02  ................
[ 3881.706534] [tempesta tls]         000000e0: 03 00 16 00 00 00 17 00 00                       .........
[ 3886.371464] [tempesta fw]     got state via sysctl: stop
[ 3886.373234] [tempesta fw] Stopping all modules...
[ 3886.374777] [tempesta fw]     mod_stop(): http_tbl
[ 3886.376557] [tempesta fw]     mod_stop(): procfs
[ 3886.378176] [tempesta fw]     mod_stop(): sock_clnt
[ 3886.379456] [tempesta tls]   write close notify
[ 3886.380591] [tempesta fw]     mod_stop(): sock_srv
[ 3886.381913] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd25540]
[ 3886.383428] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd25540]
[ 3886.384977] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd247c0]
[ 3886.386509] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd247c0]
[ 3886.388152] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd24e80]
[ 3886.389605] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd24e80]
[ 3886.390930] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd24b20]
[ 3886.392298] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd24b20]
[ 3886.393680] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd258a0]
[ 3886.394993] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd258a0]
[ 3886.397204] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd86420]
[ 3886.398647] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd86420]
[ 3886.400471] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd87500]
[ 3886.402390] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd87500]
[ 3886.404166] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd86780]
[ 3886.405790] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd86780]
[ 3886.407473] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd86e40]
[ 3886.409082] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd86e40]
[ 3886.410995] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd86ae0]
[ 3886.412638] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd86ae0]
[ 3886.414090] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd87860]
[ 3886.415494] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd87860]
[ 3886.416842] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd871a0]
[ 3886.418147] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd871a0]
[ 3886.419575] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd860c0]
[ 3886.420734] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd860c0]
[ 3886.421960] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd87bc0]
[ 3886.423296] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd87bc0]
[ 3886.424544] [tempesta fw]     tfw_http_conn_drop: conn=[ffff890144ff8080]
[ 3886.425978] [tempesta fw]     tfw_http_conn_release: conn=[ffff890144ff8080]
[ 3886.428338] [tempesta fw]     tfw_http_conn_drop: conn=[ffff890144ff9b80]
[ 3886.429611] [tempesta fw]     tfw_http_conn_release: conn=[ffff890144ff9b80]
[ 3886.431063] [tempesta fw]     tfw_http_conn_drop: conn=[ffff890144ff83e0]
[ 3886.432518] [tempesta fw]     tfw_http_conn_release: conn=[ffff890144ff83e0]
[ 3886.434034] [tempesta fw]     tfw_http_conn_drop: conn=[ffff890144ff94c0]
[ 3886.435525] [tempesta fw]     tfw_http_conn_release: conn=[ffff890144ff94c0]
[ 3886.437125] [tempesta fw]     tfw_http_conn_drop: conn=[ffff890144ff8740]
[ 3886.438660] [tempesta fw]     tfw_http_conn_release: conn=[ffff890144ff8740]
[ 3886.440109] [tempesta fw]     tfw_http_conn_drop: conn=[ffff890144ff8e00]
[ 3886.441533] [tempesta fw]     tfw_http_conn_release: conn=[ffff890144ff8e00]
[ 3886.442842] [tempesta fw]     tfw_http_conn_drop: conn=[ffff890144ff8aa0]
[ 3886.444047] [tempesta fw]     tfw_http_conn_release: conn=[ffff890144ff8aa0]
[ 3886.445236] [tempesta fw]     tfw_http_conn_drop: conn=[ffff890144ff9820]
[ 3886.446501] [tempesta fw]     tfw_http_conn_release: conn=[ffff890144ff9820]
[ 3886.447710] [tempesta fw]     tfw_http_conn_drop: conn=[ffff890144ff9160]
[ 3886.449012] [tempesta fw]     tfw_http_conn_release: conn=[ffff890144ff9160]
[ 3886.450274] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd14a60]
[ 3886.451446] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd14a60]
[ 3886.452733] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd157e0]
[ 3886.454065] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd157e0]
[ 3886.455232] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd15120]
[ 3886.457600] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd15120]
[ 3886.459034] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd14040]
[ 3886.460549] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd14040]
[ 3886.461770] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd15b40]
[ 3886.462961] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd15b40]
[ 3886.464468] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd143a0]
[ 3886.466047] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd143a0]
[ 3886.467765] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd15480]
[ 3886.469398] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd15480]
[ 3886.471032] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd14700]
[ 3886.472651] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd14700]
[ 3886.474210] [tempesta fw]     tfw_http_conn_drop: conn=[ffff89012fd14dc0]
[ 3886.475633] [tempesta fw]     tfw_http_conn_release: conn=[ffff89012fd14dc0]
[ 3886.477039] [tempesta fw]     Stop scheduler 'ratio' for group 'default'
[ 3886.478575] [tempesta fw]     Remove backend server from group 'default'
[ 3886.489781] [tempesta fw]     mod_stop(): client
[ 3886.501855] [tdb] Close table 'client0.tdb'
[ 3886.503601] [tempesta fw]     mod_stop(): http_sess
[ 3886.505457] [tempesta fw]     mod_stop(): cache
[ 3886.506901] [tempesta fw]     mod_stop(): filter
[ 3886.543783] [tdb] Close table 'filter0.tdb'
[ 3886.544903] [tempesta fw]     mod_stop(): http
[ 3886.545974] [tempesta fw]     mod_stop(): tls
[ 3886.547678] [tempesta fw]     mod_stop(): vhost
[ 3886.548607] [tempesta fw]     mod_stop(): apm
[ 3886.549797] [tempesta fw] modules are stopped
[ 3891.553605] [tempesta fw] Warning: pending active connections for 5s (connections count 0x1, queues count 0)
[ 3891.555282] [tempesta fw] Warning:   cpu 0(0), backlog size 0, work queue size 0
[ 3891.557716] [tempesta fw] Warning:   cpu 1(0), backlog size 0, work queue size 0
[ 3891.559040] [tempesta fw] Warning: Memory leakage is possible
[ 3891.573757] [tempesta fw]     release group: 'default'
[ 3891.575601] [tempesta fw] New configuration is cleaned.
[ 3891.581568] [tempesta fw] exiting...
[ 3891.584128] [tempesta fw]   ratio: exit
[ 3891.587144] [tempesta fw] Un-registering scheduler: ratio
[ 3891.590374] [tempesta fw]   sched_hash: exit
[ 3891.591597] [tempesta fw] Un-registering scheduler: hash
[ 3891.593035] [tempesta fw]     tfw_mod_unregister: http_tbl
[ 3891.594362] [tempesta fw]     tfw_mod_unregister: procfs
[ 3891.595772] [tempesta fw]     tfw_mod_unregister: sock_clnt
[ 3891.597137] kmem_cache_destroy tfw_h2_conn_cache: Slab cache still has objects
[ 3891.598701] CPU: 1 PID: 1099 Comm: rmmod Tainted: G           O    4.14.32-kdump+ #142
[ 3891.600568] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-2.fc30 04/01/2014
[ 3891.602435] Call Trace:
[ 3891.603182]  dump_stack+0x46/0x5a
[ 3891.604028]  kmem_cache_destroy+0x1c3/0x1d0
[ 3891.604941]  tfw_sock_clnt_exit+0x1c/0x30 [tempesta_fw]
[ 3891.606083]  ? tfw_sock_clnt_init+0xb0/0xb0 [tempesta_fw]
[ 3891.607128]  tfw_exit+0x3f/0x60 [tempesta_fw]
[ 3891.608186]  SyS_delete_module+0x19a/0x250
[ 3891.609046]  do_syscall_64+0x61/0x110
[ 3891.609922]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
[ 3891.610933] RIP: 0033:0x7ff65642afd7
[ 3891.611731] RSP: 002b:00007ffcda848a58 EFLAGS: 00000206 ORIG_RAX: 00000000000000b0
[ 3891.613156] RAX: ffffffffffffffda RBX: 00007ffcda848aa8 RCX: 00007ff65642afd7
[ 3891.614604] RDX: 000000000000000a RSI: 0000000000000800 RDI: 000055d082343258
[ 3891.615852] RBP: 000055d0823431f0 R08: 00007ffcda8479d1 R09: 000000000000000a
[ 3891.618684] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffcda848c70
[ 3891.620041] R13: 00007ffcda849e29 R14: 0000000000000000 R15: 000055d0823431f0
[ 3891.621633] [tempesta fw]     tfw_mod_unregister: sock_srv
[ 3891.623079] [tempesta fw]     tfw_mod_unregister: client
[ 3891.641794] [tempesta fw]     tfw_mod_unregister: http_sess
[ 3891.645099] [tempesta fw]     tfw_mod_unregister: cache
[ 3891.651445] [tempesta fw]     tfw_mod_unregister: filter
[ 3891.654979] [tempesta fw]   frang exit
[ 3891.656173] [tempesta fw] Unregistering classifier: frang
[ 3891.693743] [tempesta fw]     tfw_mod_unregister: http

krizhanovsky added a commit to tempesta-tech/tempesta-test that referenced this issue Jun 27, 2019
@krizhanovsky
Preliminary deproxy ssl support. The code doesn't work, but
38708b9 
nicely reproduce tempesta-tech/tempesta#1277
@krizhanovsky
Copy link
Contributor Author

Just got one more crash. I pushed current state of TLS integrity test tempesta-tech/tempesta-test@38708b9 - just run the code as

# ./run_tests.py -n tls.test_tls_integrity

and see the crash in a moment.

This is a showstopper, so make it crucial.

@krizhanovsky
Copy link
Contributor Author

From handshake message: msglen=233 type=1 hslen=229 read=9 it turns out that the python script sends the whole ClientHello, but Tempesta fails in processing, so there a 2 issues: (1) wrong failure on TLS ClientHello parsing and (2) the unfreed handshake data.

@krizhanovsky krizhanovsky self-assigned this Jun 28, 2019
krizhanovsky added a commit that referenced this issue Jun 28, 2019
@krizhanovsky
#1277: fix fist TLS extension parsing, unfreed handshakes problem sti…
4b3bd0d 
…ll exists
krizhanovsky added a commit that referenced this issue Jun 28, 2019
@krizhanovsky
Merge pull request #1280 from tempesta-tech/ak-1277
6f424ff 
#1277: fix TLS extension parsing
i-rinat pushed a commit that referenced this issue Jul 1, 2019
@krizhanovsky @i-rinat
#1277: fix fist TLS extension parsing, unfreed handshakes problem sti…
bae458a 
…ll exists
@vankoven vankoven mentioned this issue Jul 3, 2019
Merged
@vankoven
Copy link
Contributor

vankoven commented Jul 4, 2019

Crashes and (mem leaks) has happened because tls connections wasn't closed and remain active after Tempesta shutdown, if the handshake is not finished. The issue was resolved in 3d704b2

The second issue related to wrong failure on TLS ClientHello parsing was resolved in 4b3bd0d

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@krizhanovsky krizhanovsky

@i-rinat i-rinat

Labels
bug crucial
Projects
None yet
Milestone
0.7 - HTTP/2
Development

Successfully merging a pull request may close this issue.

tls: close connection if handshake is not done tempesta-tech/tempesta
3 participants
@krizhanovsky @i-rinat @vankoven