Closed vankoven closed 5 years ago
krizhanovsky
commented
6 years ago Probably the same problem with non-updating socket memory after adjusting skb size as in https://github.com/tempesta-tech/linux-4.9.35-tfw/commit/60883ec7aeec1000af98b69e62ec173ff5c1b988
krizhanovsky
commented
6 years ago Just hit the bug on Tempesta FW proxying 5000-byte index.html sericed by Nginx running on the same VM with Tempesta FW:
# cat ~/tempesta/etc/tempesta_fw.conf
listen 192.168.100.4:80;
server 127.0.0.1:9090;
cache 0;# ulimit -n 65536; ./wrk -c 4096 -t 8 -d 30 http://192.168.100.4:80/[11329969575.738787] [tdb] Start Tempesta DB
[11329969575.759262] [tempesta] Initializing Tempesta FW kernel module...
[11329969575.768698] [tempesta] Registering new scheduler: hash
[11329969575.776608] [tempesta] Registering new scheduler: http
[11329969575.807501] [tdb] Opened table /opt/tempesta/db/filter.tdb: size=16777216 rec_size=20 base=ffff8d0cba800000
[11329969589.422002] TCP: request_sock_TCP: Possible SYN flooding on port 80. Sending cookies. Check SNMP counters.
[11329969616.403364] ------------[ cut here ]------------
[11329969616.407433] WARNING: CPU: 3 PID: 28 at net/core/stream.c:205 sk_stream_kill_queues+0x106/0x120
[11329969616.411813] Modules linked in: tfw_sched_ratio(O) tfw_sched_http(O) tfw_sched_hash(O) tempesta_fw(O) tempesta_db(O) tempesta_tls(O) tcp_diag inet_diag kmemcpy(O) binfmt_misc crct10dif_pclmul ghash_clmulni_intel pcbc aesni_intel aes_x86_64 bochs_drm ttm drm_kms_helper drm fb_sys_fops syscopyarea crypto_simd glue_helper cryptd ppdev parport_pc sysfillrect sysimgblt parport serio_raw sg button pcspkr ip_tables x_tables autofs4 ext4 crc16 mbcache jbd2 fscrypto sr_mod cdrom sd_mod ata_generic ata_piix libata i2c_piix4 psmouse scsi_mod e1000 [last unloaded: tempesta_tls]
[11329969616.430415] CPU: 3 PID: 28 Comm: ksoftirqd/3 Tainted: G O 4.14.32-kdump+ #1
[11329969616.433921] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-2.fc27 04/01/2014
[11329969616.437326] task: ffff8d0c9acfb1c0 task.stack: ffffafce00418000
[11329969616.441104] RIP: 0010:sk_stream_kill_queues+0x106/0x120
[11329969616.444787] RSP: 0018:ffffafce0041bb08 EFLAGS: 00010286
[11329969616.447491] RAX: 00000000ffffff00 RBX: ffff8d0c9a6f7000 RCX: 0000000000000020
[11329969616.449393] RDX: ffffffffffffffe0 RSI: 0000000000000100 RDI: ffff8d0c9a6f70b0
[11329969616.451050] RBP: ffff8d0c9a6f70b0 R08: 0000000000000000 R09: 0000000000000000
[11329969616.452854] R10: 0000000000000001 R11: 0000000000015bc6 R12: ffff8d0c9a6f7158
[11329969616.454647] R13: ffff8d0c9749fc62 R14: ffff8d0c9749fc62 R15: ffff8d0c9a6f7000
[11329969616.456506] FS: 0000000000000000(0000) GS:ffff8d0cbfd80000(0000) knlGS:0000000000000000
[11329969616.458783] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[11329969616.462618] CR2: 00005575e4992628 CR3: 000000007c80a003 CR4: 00000000003606e0
[11329969616.464943] Call Trace:
[11329969616.466191] inet_csk_destroy_sock+0x50/0x100
[11329969616.467667] ss_linkerror+0x9/0x60 [tempesta_fw]
[11329969616.469242] tcp_reset+0x129/0x170
[11329969616.470692] tcp_validate_incoming+0x124/0x3f0
[11329969616.473524] tcp_rcv_established+0x1ca/0x570
[11329969616.475004] ? tcp_v4_inbound_md5_hash+0x5d/0x1b0
[11329969616.476537] tcp_v4_do_rcv+0x124/0x1c0
[11329969616.477840] tcp_v4_rcv+0x93f/0xa40
[11329969616.479207] ip_local_deliver_finish+0x95/0x1c0
[11329969616.480775] ip_local_deliver+0x66/0xe0
[11329969616.482553] ? tcp_v4_early_demux+0x10d/0x140
[11329969616.484080] ? ip_rcv_finish+0x175/0x400
[11329969616.485643] ip_rcv+0x284/0x3b0
[11329969616.486950] ? inet_del_offload+0x30/0x30
[11329969616.488636] __netif_receive_skb_core+0x84a/0xb30
[11329969616.492160] ? process_backlog+0x92/0x120
[11329969616.494935] process_backlog+0x92/0x120
[11329969616.496660] net_rx_action+0x261/0x3a0
[11329969616.498065] __do_softirq+0x104/0x297Looks very close to #926, it seems socket buffers weren't updated in all the places correctly.
krizhanovsky
commented
6 years ago Just got plenty of net/ipv4/af_inet.c:155 inet_sock_destruct warnings on tests from https://github.com/tempesta-tech/tempesta/issues/635#issuecomment-383745388 on hardware testbed, so the issues is kind of crucial.
krizhanovsky
commented
5 years ago The assertions fail on client sockets on Tempesta FW's side and seem caused by wrong data writings to the client sockets.
Able to reproduce the issue just with
wrk -d 10 -c 2 -t 1 http://192.168.100.4/index.html, where index.html is ~19KB file. Some concurrency is required - I couldn't reproduce the issue for only one connection. Also I couldn't hit the problem for very small (~20B) files. HTTP headers adjustment seems doesn't affect the issue anyhow.
Only one backend connection is enough:
# cat etc/tempesta_fw.conf
listen 192.168.100.4:80;
srv_group default {
server 127.0.0.1:8080 conns_n=1;
}
vhost default {
proxy_pass default;
}
cache 0;
http_chain {
-> default;
}However, bigger number of backend connections doesn't affect the issue. There are no connection resets from the Apache backend.
One more concurrency scenario to reproduce the issue is putting single connection to a backend directly and one more through Tempesta:
$ wrk -d 600 -c 1 -t 1 http://192.168.100.4:8080/index.html
$ wrk -d 5 -c 1 -t 1 http://192.168.100.4/index.htmlAgain, both the connections must request the big file, if only one of them requests the big file while the other one requests a small file, then the warnings don't appear.
Tempesta is at 7ee5ded650e97d986f39b278294b824932a9b88e linux kernel is at
4.9.35-tfw6tag (latest release). Simply runregression.test_stress_pipeline.Pipelinefunctional tests and multiple oopses will happen onwrkshutdown (client disconnects). At least100concurrent connections was required to reproduce the issue.Test log:
Kernel log (a part of it since it was flooded and overflowed):
Seems that same Oopses was seen in #692