What are we doing about these kernel traces?
They don’t look like we can ignore them.
-Michael
On 19 Sep 2019, at 21:16, peter.mueller@ipfire.org wrote:
Hello Stefan,
sorry for my late reply on this topic. Finally, I was able to test your new ISO, next-suricata-rust/d22217e1-dirty .
New connections, regardless of SSH, TLS, DNS or whatever, are now established instantly. No packets are dropped anymore, this issue seems to be solved by the changes included in your ISO.
OpenVPN RW performance, however, is worse than before: Now around ~ 400 kB/sec. if Suricata is enabled, and somewhere around 900 kB/sec. if it is not. I am getting the feeling this is an OpenVPN bug or performance issue, but as mentioned several times before, I am not satisfied with OpenVPN anyway.
A few minutes after booting, kernel emits these log lines:
Sep 19 22:01:51 maverick kernel: refcount_t: increment on 0; use-after-free. Sep 19 22:01:51 maverick kernel: ------------[ cut here ]------------ Sep 19 22:01:51 maverick kernel: WARNING: CPU: 2 PID: 2510 at lib/refcount.c:153 refcount_inc.cold.12+0x13/0x16 Sep 19 22:01:51 maverick kernel: Modules linked in: xt_IMQ imq xt_length xt_DSCP xt_layer7 cls_fw sch_htb chacha20_x86_64 chacha20_generic poly1305_x86_64 poly1305_generic chacha20poly1305 esp4 xfrm6_mode_tunnel xfrm4_mode_tunnel tun nfnetlink_queue xt_NFQUEUE ipt_MASQUERADE nf_nat_masquerade_ipv4 pppoe pppox ppp_generic slhc xt_geoip(O) xt_connlimit xt_multiport xt_hashlimit xt_mark xt_policy xt_TCPMSS nf_nat_irc nf_conntrack_irc nf_nat_tftp nf_conntrack_tftp nf_nat_ftp nf_conntrack_ftp xt_CT xt_helper nf_nat_h323 nf_conntrack_h323 xt_conntrack xt_comment ipt_REJECT nf_reject_ipv4 nf_log_ipv4 nf_log_common xt_LOG xt_limit iptable_raw iptable_mangle iptable_filter vfat fat snd_hda_codec_hdmi sch_fq_codel snd_hda_codec_realtek snd_hda_codec_generic intel_powerclamp coretemp kvm_intel i2c_algo_bit fb_sys_fops syscopyarea Sep 19 22:01:51 maverick kernel: sysfillrect sysimgblt snd_hda_intel kvm snd_hda_codec snd_hda_core iTCO_wdt iTCO_vendor_support irqbypass snd_hwdep crct10dif_pclmul mcs7830 crc32_pclmul snd_pcm ghash_clmulni_intel snd_timer usbnet r8169 pcspkr snd i2c_i801 lpc_ich mfd_core mii soundcore i2c_hid i2c_core pcc_cpufreq rfkill_gpio rfkill intel_int0002_vgpio lp parport_pc parport video Sep 19 22:01:51 maverick kernel: CPU: 2 PID: 2510 Comm: W-Q3 Tainted: G O 4.14.138-ipfire #1 Sep 19 22:01:51 maverick kernel: Hardware name: Gigabyte Technology Co., Ltd. Default string/N3150ND3V, BIOS F5a 01/19/2018 Sep 19 22:01:51 maverick kernel: task: ffffa393374fb200 task.stack: ffffa98f00290000 Sep 19 22:01:51 maverick kernel: RIP: 0010:refcount_inc.cold.12+0x13/0x16 Sep 19 22:01:51 maverick kernel: RSP: 0018:ffffa98f00293798 EFLAGS: 00010246 Sep 19 22:01:51 maverick kernel: RAX: 000000000000002b RBX: ffffa39338e7ed00 RCX: 0000000000000000 Sep 19 22:01:51 maverick kernel: RDX: 0000000000000000 RSI: ffffa3933fd163f8 RDI: ffffa3933fd163f8 Sep 19 22:01:51 maverick kernel: RBP: ffffffffb3e9e220 R08: 000000000000003c R09: 000000000000027c Sep 19 22:01:51 maverick kernel: R10: 0000000000000000 R11: 0000000000000001 R12: ffffa39338c81100 Sep 19 22:01:51 maverick kernel: R13: ffffffffb44c35c0 R14: 0000000000028003 R15: ffffffffc03fc3e0 Sep 19 22:01:51 maverick kernel: FS: 00007309737fe700(0000) GS:ffffa3933fd00000(0000) knlGS:0000000000000000 Sep 19 22:01:51 maverick kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Sep 19 22:01:51 maverick kernel: CR2: 00007eb62b581728 CR3: 0000000177e30000 CR4: 00000000001006e0 Sep 19 22:01:51 maverick kernel: Call Trace: Sep 19 22:01:51 maverick kernel: nf_queue_entry_get_refs+0x41/0x90 Sep 19 22:01:51 maverick kernel: nf_queue+0xf9/0x220 Sep 19 22:01:51 maverick kernel: nf_hook_slow+0x9f/0xf0 Sep 19 22:01:51 maverick kernel: __ip_local_out+0xe4/0x150 Sep 19 22:01:51 maverick kernel: ? ip_forward_options.cold.7+0x27/0x27 Sep 19 22:01:51 maverick kernel: xfrm_output_resume+0x21e/0x540 Sep 19 22:01:51 maverick kernel: ? ipv4_confirm+0x3f/0xd0 Sep 19 22:01:51 maverick kernel: xfrm4_output+0x3a/0xe0 Sep 19 22:01:51 maverick kernel: ? xfrm4_udp_encap_rcv+0x1a0/0x1a0 Sep 19 22:01:51 maverick kernel: nf_reinject+0x176/0x190 Sep 19 22:01:51 maverick kernel: nfqnl_recv_verdict+0x293/0x4a0 [nfnetlink_queue] Sep 19 22:01:51 maverick kernel: ? nla_parse+0xb5/0xe0 Sep 19 22:01:51 maverick kernel: nfnetlink_rcv_msg+0x14e/0x260 Sep 19 22:01:51 maverick kernel: ? nfnetlink_net_exit_batch+0x60/0x60 Sep 19 22:01:51 maverick kernel: netlink_rcv_skb+0x78/0x150 Sep 19 22:01:51 maverick kernel: nfnetlink_rcv+0x70/0x760 Sep 19 22:01:51 maverick kernel: ? lock_timer_base+0x67/0x80 Sep 19 22:01:51 maverick kernel: ? try_to_del_timer_sync+0x4d/0x80 Sep 19 22:01:51 maverick kernel: ? __netlink_lookup+0xe1/0x140 Sep 19 22:01:51 maverick kernel: netlink_unicast+0x183/0x230 Sep 19 22:01:51 maverick kernel: netlink_sendmsg+0x204/0x3d0 Sep 19 22:01:51 maverick kernel: sock_sendmsg+0x36/0x40 Sep 19 22:01:51 maverick kernel: ___sys_sendmsg+0x2a7/0x300 Sep 19 22:01:51 maverick kernel: ? netlink_recvmsg+0x398/0x460 Sep 19 22:01:51 maverick kernel: ? __switch_to_asm+0x41/0x70 Sep 19 22:01:51 maverick kernel: __sys_sendmsg+0x67/0xb0 Sep 19 22:01:51 maverick kernel: do_syscall_64+0x67/0x100 Sep 19 22:01:51 maverick kernel: entry_SYSCALL_64_after_hwframe+0x3d/0xa2 Sep 19 22:01:51 maverick kernel: RIP: 0033:0x73097af4a8c7 Sep 19 22:01:51 maverick kernel: RSP: 002b:00007309737fbfc0 EFLAGS: 00000293 ORIG_RAX: 000000000000002e Sep 19 22:01:51 maverick kernel: RAX: ffffffffffffffda RBX: 0000000000000008 RCX: 000073097af4a8c7 Sep 19 22:01:51 maverick kernel: RDX: 0000000000000000 RSI: 00007309737fc000 RDI: 0000000000000008 Sep 19 22:01:51 maverick kernel: RBP: 00007309737fc000 R08: 0000000000000000 R09: 0000000000000301 Sep 19 22:01:51 maverick kernel: R10: 0000730974409e20 R11: 0000000000000293 R12: 0000000000000000 Sep 19 22:01:51 maverick kernel: R13: 000073096026cd98 R14: 0000000000000070 R15: 0000000000000001 Sep 19 22:01:51 maverick kernel: Code: 08 90 67 b4 c6 05 5e ca d8 00 01 e8 f7 e5 d7 ff 0f 0b b8 01 00 00 00 c3 48 c7 c7 60 90 67 b4 c6 05 42 ca d8 00 01 e8 dc e5 d7 ff <0f> 0b c3 48 c7 c7 90 90 67 b4 c6 05 2b ca d8 00 01 e8 c6 e5 d7 Sep 19 22:01:51 maverick kernel: ---[ end trace dc2e33bbb9167d28 ]--- Sep 19 22:01:51 maverick kernel: refcount_t: underflow; use-after-free. Sep 19 22:01:51 maverick kernel: ------------[ cut here ]------------ Sep 19 22:01:51 maverick kernel: WARNING: CPU: 3 PID: 2507 at lib/refcount.c:187 refcount_sub_and_test.cold.13+0x13/0x1a Sep 19 22:01:51 maverick kernel: Modules linked in: xt_IMQ imq xt_length xt_DSCP xt_layer7 cls_fw sch_htb chacha20_x86_64 chacha20_generic poly1305_x86_64 poly1305_generic chacha20poly1305 esp4 xfrm6_mode_tunnel xfrm4_mode_tunnel tun nfnetlink_queue xt_NFQUEUE ipt_MASQUERADE nf_nat_masquerade_ipv4 pppoe pppox ppp_generic slhc xt_geoip(O) xt_connlimit xt_multiport xt_hashlimit xt_mark xt_policy xt_TCPMSS nf_nat_irc nf_conntrack_irc nf_nat_tftp nf_conntrack_tftp nf_nat_ftp nf_conntrack_ftp xt_CT xt_helper nf_nat_h323 nf_conntrack_h323 xt_conntrack xt_comment ipt_REJECT nf_reject_ipv4 nf_log_ipv4 nf_log_common xt_LOG xt_limit iptable_raw iptable_mangle iptable_filter vfat fat snd_hda_codec_hdmi sch_fq_codel snd_hda_codec_realtek snd_hda_codec_generic intel_powerclamp coretemp kvm_intel i2c_algo_bit fb_sys_fops syscopyarea Sep 19 22:01:51 maverick kernel: sysfillrect sysimgblt snd_hda_intel kvm snd_hda_codec snd_hda_core iTCO_wdt iTCO_vendor_support irqbypass snd_hwdep crct10dif_pclmul mcs7830 crc32_pclmul snd_pcm ghash_clmulni_intel snd_timer usbnet r8169 pcspkr snd i2c_i801 lpc_ich mfd_core mii soundcore i2c_hid i2c_core pcc_cpufreq rfkill_gpio rfkill intel_int0002_vgpio lp parport_pc parport video Sep 19 22:01:51 maverick kernel: CPU: 3 PID: 2507 Comm: W-Q2 Tainted: G W O 4.14.138-ipfire #1 Sep 19 22:01:51 maverick kernel: Hardware name: Gigabyte Technology Co., Ltd. Default string/N3150ND3V, BIOS F5a 01/19/2018 Sep 19 22:01:51 maverick kernel: task: ffffa393395ea580 task.stack: ffffa98f00250000 Sep 19 22:01:51 maverick kernel: RIP: 0010:refcount_sub_and_test.cold.13+0x13/0x1a Sep 19 22:01:51 maverick kernel: RSP: 0018:ffffa98f00253928 EFLAGS: 00010246 Sep 19 22:01:51 maverick kernel: RAX: 0000000000000026 RBX: 0000000000000000 RCX: 0000000000000000 Sep 19 22:01:51 maverick kernel: RDX: 0000000000000000 RSI: ffffa3933fd963f8 RDI: ffffa3933fd963f8 Sep 19 22:01:51 maverick kernel: RBP: ffffa39339bc4400 R08: 0000000000000038 R09: 00000000000002b4 Sep 19 22:01:51 maverick kernel: R10: 0000000000000000 R11: 0000000000000001 R12: ffffa393383ab480 Sep 19 22:01:51 maverick kernel: R13: ffffa39337f5da00 R14: ffffa39339cd9840 R15: 0000000000000000 Sep 19 22:01:51 maverick kernel: FS: 0000730973fff700(0000) GS:ffffa3933fd80000(0000) knlGS:0000000000000000 Sep 19 22:01:51 maverick kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Sep 19 22:01:51 maverick kernel: CR2: 0000000002218828 CR3: 0000000177e30000 CR4: 00000000001006e0 Sep 19 22:01:51 maverick kernel: Call Trace: Sep 19 22:01:51 maverick kernel: nf_queue_entry_release_refs+0x45/0xa0 Sep 19 22:01:51 maverick kernel: nf_reinject+0x3d/0x190 Sep 19 22:01:51 maverick kernel: nfqnl_recv_verdict+0x293/0x4a0 [nfnetlink_queue] Sep 19 22:01:51 maverick kernel: ? nla_parse+0xb5/0xe0 Sep 19 22:01:51 maverick kernel: nfnetlink_rcv_msg+0x14e/0x260 Sep 19 22:01:51 maverick kernel: ? nfnetlink_net_exit_batch+0x60/0x60 Sep 19 22:01:51 maverick kernel: netlink_rcv_skb+0x78/0x150 Sep 19 22:01:51 maverick kernel: nfnetlink_rcv+0x70/0x760 Sep 19 22:01:51 maverick kernel: ? lock_timer_base+0x67/0x80 Sep 19 22:01:51 maverick kernel: ? try_to_del_timer_sync+0x4d/0x80 Sep 19 22:01:51 maverick kernel: ? __netlink_lookup+0xe1/0x140 Sep 19 22:01:51 maverick kernel: netlink_unicast+0x183/0x230 Sep 19 22:01:51 maverick kernel: netlink_sendmsg+0x204/0x3d0 Sep 19 22:01:51 maverick kernel: sock_sendmsg+0x36/0x40 Sep 19 22:01:51 maverick kernel: ___sys_sendmsg+0x2a7/0x300 Sep 19 22:01:51 maverick kernel: ? netlink_recvmsg+0x398/0x460 Sep 19 22:01:51 maverick kernel: ? __switch_to_asm+0x41/0x70 Sep 19 22:01:51 maverick kernel: __sys_sendmsg+0x67/0xb0 Sep 19 22:01:51 maverick kernel: do_syscall_64+0x67/0x100 Sep 19 22:01:51 maverick kernel: entry_SYSCALL_64_after_hwframe+0x3d/0xa2 Sep 19 22:01:51 maverick kernel: RIP: 0033:0x73097af4a8c7 Sep 19 22:01:51 maverick kernel: RSP: 002b:0000730973ffcfc0 EFLAGS: 00000293 ORIG_RAX: 000000000000002e Sep 19 22:01:51 maverick kernel: RAX: ffffffffffffffda RBX: 0000000000000007 RCX: 000073097af4a8c7 Sep 19 22:01:51 maverick kernel: RDX: 0000000000000000 RSI: 0000730973ffd000 RDI: 0000000000000007 Sep 19 22:01:51 maverick kernel: RBP: 0000730973ffd000 R08: 0000000000000000 R09: 0000000000000301 Sep 19 22:01:51 maverick kernel: R10: 000073096826c188 R11: 0000000000000293 R12: 0000000000000000 Sep 19 22:01:51 maverick kernel: R13: 000073096826cd98 R14: 0000000065000070 R15: 0000000000000001 Sep 19 22:01:51 maverick kernel: Code: 00 c3 48 c7 c7 60 90 67 b4 c6 05 42 ca d8 00 01 e8 dc e5 d7 ff 0f 0b c3 48 c7 c7 90 90 67 b4 c6 05 2b ca d8 00 01 e8 c6 e5 d7 ff <0f> 0b e9 86 fe ff ff 48 c7 c7 b8 90 67 b4 c6 05 10 ca d8 00 01 Sep 19 22:01:51 maverick kernel: ---[ end trace dc2e33bbb9167d29 ]---
Suricata works correctly and detects attacks as expected. Starting sequence took about 83 seconds on my testing hardware.
In my point of view, the ISO includes all necessary fixes for curing our Suricata problems - slow establish of new connections, DNS trouble, et cetera - and I would like them to be included in the next Core Update (testing) so we can give it a bigger and more extensive test. What do you think about this?
OpenVPN performance is poor, but I guess that is because of something else.
Command outputs for reference:
[root@maverick ~]# uname -a Linux maverick 4.14.138-ipfire #1 SMP Mon Sep 9 07:55:34 GMT 2019 x86_64 Intel(R) Celeron(R) CPU N3150 @ 1.60GHz GenuineIntel GNU/Linux
[root@maverick ~]# suricata -V This is Suricata version 4.1.4 RELEASE
[root@maverick ~]# suricata --build-info This is Suricata version 4.1.4 RELEASE Features: NFQ PCAP_SET_BUFF AF_PACKET HAVE_PACKET_FANOUT LIBCAP_NG LIBNET1.1 HAVE_HTP_URI_NORMALIZE_HOOK PCRE_JIT HAVE_LIBJANSSON TLS MAGIC RUST SIMD support: none Atomic intrisics: 1 2 4 8 byte(s) 64-bits, Little-endian architecture GCC version 8.3.0, C version 199901 compiled with _FORTIFY_SOURCE=2 L1 cache line size (CLS)=64 thread local storage method: __thread compiled with LibHTP v0.5.30, linked against LibHTP v0.5.30
Suricata Configuration: AF_PACKET support: yes eBPF support: no XDP support: no PF_RING support: no NFQueue support: yes NFLOG support: no IPFW support: no Netmap support: no DAG enabled: no Napatech enabled: no WinDivert enabled: no
Unix socket enabled: yes Detection enabled: yes
Libmagic support: yes libnss support: no libnspr support: no libjansson support: yes liblzma support: yes hiredis support: no hiredis async with libevent: no Prelude support: no PCRE jit: yes LUA support: no libluajit: no libgeoip: no Non-bundled htp: yes Old barnyard2 support: no Hyperscan support: yes Libnet support: yes liblz4 support: no
Rust support: yes Rust strict mode: no Rust debug mode: no Rust compiler: rustc 1.37.0 (eae3437df 2019-08-13) Rust cargo: cargo 1.37.0 (9edd08916 2019-08-02)
Install suricatasc: no Install suricata-update: no
Profiling enabled: no Profiling locks enabled: no
Development settings: Coccinelle / spatch: no Unit tests enabled: no Debug output enabled: no Debug validation enabled: no
Generic build parameters: Installation prefix: /usr Configuration directory: /etc/suricata/ Log directory: /var/log/suricata/
--prefix /usr --sysconfdir /etc --localstatedir /var --datarootdir /usr/share
Host: x86_64-pc-linux-gnu Compiler: gcc (exec name) / gcc (real) GCC Protect enabled: yes GCC march native enabled: no GCC Profile enabled: no Position Independent Executable enabled: no CFLAGS -O2 -pipe -Wall -fexceptions -fPIC -m64 -mindirect-branch=thunk -mfunction-return=thunk -mtune=generic -Wp,-D_FORTIFY_SOURCE=2 -Wp,-D_GLIBCXX_ASSERTIONS -fstack-protector-strong -I${srcdir}/../rust/gen/c-headers PCAP_CFLAGS -I/usr/include SECCFLAGS -fstack-protector -D_FORTIFY_SOURCE=2 -Wformat -Wformat-security
Thanks, and best regards, Peter Müller