Hi,
today it happened again - at 1:18am:
***SNIP*** ipfire kernel: refcount_t: underflow; use-after-free. ipfire kernel: WARNING: CPU: 1 PID: 30228 at lib/refcount.c:28 refcount_warn_saturate+0xa6/0xf0 ipfire kernel: Modules linked in: xt_REDIRECT nfnetlink_queue xt_NFQUEUE xt_MASQUERADE ccm cpufreq_conservative cpufreq_ondemand xt_geoip(O) xt_ipp2p(O) compat_xtables(O) xt_hashlimit xt_mac xt_multiport xt_mark xt_policy xt_TCPMSS xt_conntrack xt_comment ipt_REJECT nf_reject_ipv4 xt_LOG xt_limit nf_log_ipv4 nf_log_common iptable_raw iptable_mangle iptable_filter vfat fat rt2800usb rt2x00usb rt2800lib rt2x00lib sch_fq_codel x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel mac80211 at24 kvm regmap_i2c iTCO_wdt iTCO_vendor_support irqbypass crct10dif_pclmul crc32_pclmul cfg80211 ghash_clmulni_intel i2c_i801 pcspkr i2c_smbus lpc_ich rfkill mfd_core r8169 realtek libarc4 ir_rc6_decoder i2c_algo_bit fb_sys_fops snd_hda_codec_realtek syscopyarea rc_rc6_mce sysfillrect snd_hda_codec_generic sysimgblt nuvoton_cir i2c_core ledtrig_audio rc_core snd_hda_intel snd_intel_dspcfg snd_hda_codec snd_hda_core snd_hwdep acpi_pad snd_pcm snd_timer snd soundcore lp parport_pc parport video ipfire kernel: CPU: 1 PID: 30228 Comm: W-NFQ#0 Tainted: G O 5.10.55-ipfire #1 ipfire kernel: Hardware name: To be filled by O.E.M. To be filled by O.E.M./CRESCENTBAY, BIOS 5.011 04/13/2016 ipfire kernel: RIP: 0010:refcount_warn_saturate+0xa6/0xf0 ipfire kernel: Code: 05 ba 60 1f 01 01 e8 af a3 52 00 0f 0b c3 80 3d a8 60 1f 01 00 75 95 48 c7 c7 b8 fc 11 ab c6 05 98 60 1f 01 01 e8 90 a3 52 00 <0f> 0b c3 80 3d 87 60 1f 01 00 0f 85 72 ff ff ff 48 c7 c7 10 fd 11 ipfire kernel: RSP: 0018:ffffbaba82823950 EFLAGS: 00010282 ipfire kernel: RAX: 0000000000000000 RBX: ffff998e77a25500 RCX: 0000000000000027 ipfire kernel: RDX: ffff998f47318968 RSI: 0000000000000001 RDI: ffff998f47318960 ipfire kernel: RBP: ffffbaba82823a50 R08: 0000000000000000 R09: ffffbaba82823788 ipfire kernel: R10: ffffbaba82823780 R11: ffffffffab533dc8 R12: ffff998e77a25500 ipfire kernel: R13: ffff998e04193a00 R14: 0000000000000005 R15: ffff998e03a6ea00 ipfire kernel: FS: 0000758d85125640(0000) GS:ffff998f47300000(0000) knlGS:0000000000000000 ipfire kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 ipfire kernel: CR2: 00007722aefed0a0 CR3: 000000010351e003 CR4: 00000000000706e0 ipfire kernel: Call Trace: ipfire kernel: nf_queue_entry_release_refs+0x82/0xa0 ipfire kernel: nf_reinject+0x7a/0x1e0 ipfire kernel: nfqnl_recv_verdict+0x302/0x4f0 [nfnetlink_queue] ipfire kernel: nfnetlink_rcv_msg+0x16d/0x2c0 ipfire kernel: ? nfnetlink_net_exit_batch+0x60/0x60 ipfire kernel: netlink_rcv_skb+0x5b/0x100 ipfire kernel: netlink_unicast+0x209/0x2d0 ipfire kernel: netlink_sendmsg+0x23a/0x470 ipfire kernel: sock_sendmsg+0x5e/0x60 ipfire kernel: ____sys_sendmsg+0x258/0x2a0 ipfire kernel: ___sys_sendmsg+0xa3/0xf0 ipfire kernel: __sys_sendmsg+0x81/0xd0 ipfire kernel: do_syscall_64+0x33/0x40 ipfire kernel: entry_SYSCALL_64_after_hwframe+0x44/0xa9 ipfire kernel: RIP: 0033:0x758d871bb62d ipfire kernel: Code: 28 89 54 24 1c 48 89 74 24 10 89 7c 24 08 e8 fa ee ff ff 8b 54 24 1c 48 8b 74 24 10 41 89 c0 8b 7c 24 08 b8 2e 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 33 44 89 c7 48 89 44 24 08 e8 4e ef ff ff 48 ipfire kernel: RSP: 002b:0000758d85122f40 EFLAGS: 00000293 ORIG_RAX: 000000000000002e ipfire kernel: RAX: ffffffffffffffda RBX: 0000758d80268dd0 RCX: 0000758d871bb62d ipfire kernel: RDX: 0000000000000000 RSI: 0000758d85122f80 RDI: 0000000000000005 ipfire kernel: RBP: 0000758d85122fe0 R08: 0000000000000000 R09: 0000758d8689fde0 ipfire kernel: R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000 ipfire kernel: R13: 0000000000000000 R14: 0000000000000001 R15: 0000000000000070 ipfire kernel: ---[ end trace 4c8c047c62e118e2 ]--- ***SNAP***
Machine is running without (seen) problems - I didn'T reboot yet.
Best, Matthias
On 09.09.2021 22:36, Peter Müller wrote:
Hello *,
just for the records: I noticed this behaviour while testing Core Update 140/141 (in February 2020) the first time. Not kept track on this, but it does not seem to cause any harm - at least none I am aware of. But it certainly is not a good thing to see, either...
Please refer to https://lists.ipfire.org/pipermail/development/2020-February/007046.html for further details.
Thanks, and best regards, Peter Müller
On 31 Aug 2021, at 16:25, Matthias Fischer matthias.fischer@ipfire.org wrote:
Hi,
On 31.08.2021 11:56, Michael Tremer wrote:
Hey,
This is an oops in the code that injects packets back into the kernel after they have been processed by suricata.
Wow. How did you find this out!?
There are two key functions in the trace:
1 Time(s): nf_queue_entry_release_refs+0x82/0xa0 1 Time(s): nf_reinject+0x7a/0x1e0
They are from Netfilter and the NFQUEUE module. We only use that for the IPS.
Was this a one-off or does this happen on a regular basis?
Until now, it only happened once.
It rebooted the machine - just to be sure - and its running "without seen problems" since then. Absolutely normal.
Would be interesting to see how it behaves if it doesn’t get a reboot.
This is definitely a bug and needs to be fixed in the Linux kernel.
-Michael
Best, Matthias
-Michael
On 27 Aug 2021, at 17:16, Matthias Fischer matthias.fischer@ipfire.org wrote:
Hi,
today I took the usual look in LOG SUMMARY and was surprised finding this:
***SNIP*** Kernel
WARNING: Kernel Errors Present WARNING: CPU: 0 PID: 2984 at lib/refcount.c:28 r ...: 1 Time(s)
1 Time(s): ? nfnetlink_net_exit_batch+0x60/0x60 1 Time(s): [last unloaded: hwmon_vid] 1 Time(s): ____sys_sendmsg+0x258/0x2a0 1 Time(s): ___sys_sendmsg+0xa3/0xf0 1 Time(s): __sys_sendmsg+0x81/0xd0 1 Time(s): do_syscall_64+0x33/0x40 1 Time(s): entry_SYSCALL_64_after_hwframe+0x44/0xa9 1 Time(s): netlink_rcv_skb+0x5b/0x100 1 Time(s): netlink_sendmsg+0x23a/0x470 1 Time(s): netlink_unicast+0x209/0x2d0 1 Time(s): nf_queue_entry_release_refs+0x82/0xa0 1 Time(s): nf_reinject+0x7a/0x1e0 1 Time(s): nfnetlink_rcv_msg+0x16d/0x2c0 1 Time(s): nfqnl_recv_verdict+0x302/0x4f0 [nfnetlink_queue] 1 Time(s): sock_sendmsg+0x5e/0x60 1 Time(s): ------------[ cut here ]------------ 1 Time(s): ---[ end trace 49e1e291edb98731 ]--- 1 Time(s): CPU: 0 PID: 2984 Comm: W-NFQ#1 Tainted: G O 5.10.55-ipfire #1 1 Time(s): CR2: 000079fa1356a6f8 CR3: 0000000101532004 CR4: 00000000000706f0 1 Time(s): CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 1 Time(s): Call Trace: 1 Time(s): Code: 05 ba 60 1f 01 01 e8 af a3 52 00 0f 0b c3 80 3d a8 60 1f 01 00 75 95 48 c7 c7 b8 fc 11 b4 c6 05 98 60 1f 01 01 e8 90 a3 52 00 <0f> 0b c3 80 3d 87 60 1f 01 00 0f 85 72 ff ff ff 48 c7 c7 10 fd 11 1 Time(s): Code: 28 89 54 24 1c 48 89 74 24 10 89 7c 24 08 e8 fa ee ff ff 8b 54 24 1c 48 8b 74 24 10 41 89 c0 8b 7c 24 08 b8 2e 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 33 44 89 c7 48 89 44 24 08 e8 4e ef ff ff 48 1 Time(s): FS: 00007144d27d9640(0000) GS:ffff9db887200000(0000) knlGS:0000000000000000 1 Time(s): Hardware name: To be filled by O.E.M. To be filled by O.E.M./CRESCENTBAY, BIOS 5.011 04/13/2016 1 Time(s): Modules linked in: xt_REDIRECT nfnetlink_queue xt_NFQUEUE xt_MASQUERADE ccm cpufreq_conservative cpufreq_ondemand xt_geoip(O) xt_ipp2p(O) compat_xtables(O) xt_hashlimit xt_mac xt_multiport xt_mark xt_policy xt_TCPMSS xt_conntrack xt_comment ipt_REJECT nf_reject_ipv4 xt_LOG xt_limit nf_log_ipv4 nf_log_common iptable_raw iptable_mangle iptable_filter vfat fat sch_fq_codel rt2800usb rt2x00usb x86_pkg_temp_thermal rt2800lib intel_powerclamp coretemp rt2x00lib kvm_intel mac80211 kvm at24 regmap_i2c iTCO_wdt iTCO_vendor_support irqbypass crct10dif_pclmul cfg80211 crc32_pclmul ghash_clmulni_intel pcspkr i2c_i801 rfkill r8169 lpc_ich i2c_smbus mfd_core realtek libarc4 ir_rc6_decoder rc_rc6_mce i2c_algo_bit snd_hda_codec_realtek nuvoton_cir fb_sys_fops syscopyarea sysfillrect sysimgblt snd_hda_codec_generic ledtrig_audio i2c_core rc_core snd_hda_intel snd_intel_dspcfg snd_hda_codec snd_hda_core snd_hwdep acpi_pad snd_pcm snd_timer snd soundcore lp parport_pc parport video 1 Time(s): R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000 1 Time(s): R10: ffffb330821af780 R11: ffffffffb4533dc8 R12: ffff9db791371980 1 Time(s): R13: 0000000000000000 R14: 0000000000000001 R15: 0000000000000070 1 Time(s): R13: ffff9db7444d9200 R14: 0000000000000005 R15: ffff9db7f15c6b00 1 Time(s): RAX: 0000000000000000 RBX: ffff9db791371980 RCX: 0000000000000027 1 Time(s): RAX: ffffffffffffffda RBX: 00007144c4268dd0 RCX: 00007144d507062d 1 Time(s): RBP: 00007144d27d6fe0 R08: 0000000000000000 R09: 00007144d4754de0 1 Time(s): RBP: ffffb330821afa50 R08: 0000000000000000 R09: ffffb330821af788 1 Time(s): RDX: 0000000000000000 RSI: 00007144d27d6f80 RDI: 0000000000000006 1 Time(s): RDX: ffff9db887218968 RSI: 0000000000000001 RDI: ffff9db887218960 1 Time(s): RIP: 0010:refcount_warn_saturate+0xa6/0xf0 1 Time(s): RIP: 0033:0x7144d507062d 1 Time(s): RSP: 0018:ffffb330821af950 EFLAGS: 00010282 1 Time(s): RSP: 002b:00007144d27d6f40 EFLAGS: 00000293 ORIG_RAX: 000000000000002e 1 Time(s): refcount_t: underflow; use-after-free. ***SNAP***
I don't know exactly how do deal with this - does anyone has an idea what this means?
Besides the machine is up and running with Core 159 / 64bit since 6 days now and if I hadn't looked at the logs I would not have noticed it.
I didn't reboot or changed anything yet- should I do?
Best, Matthias