Re: Core 159 - "Kernel errors present" in LOG SUMMARY

[Michael Tremer <michael.tremer@ipfire.org>]

[-- Attachment #1: Type: text/plain, Size: 12229 bytes --]

Hello Matthias,

Since we now have kernel 5.15.x in next, I would recommend installing that and check if the problem persists.

Best,
-Michael

> On 28 Nov 2021, at 14:21, Matthias Fischer <matthias.fischer(a)ipfire.org> wrote:
> 
> Hi,
> 
> On 21.09.2021 11:36, Michael Tremer wrote:
>> Hello,
>> 
>> Could we report this to the right place with the Linux kernel community?
> 
> Where would be this "right place"?
> 
> https://bugzilla.kernel.org/ or https://lkml.org/?
> 
> It happened again today with Core 161 (running 'suricata 5.0.8').
> 
> => see Attachment
> 
> Best,
> Matthias
> 
>> This seems to be a long-standing problem which wouldn’t be very difficult to solve.
>> 
>> -Michael
>> 
>>> On 20 Sep 2021, at 16:16, Matthias Fischer <matthias.fischer(a)ipfire.org> wrote:
>>> 
>>> 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(a)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(a)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
>>>>>>> 
>>>>>> 
>>>>> 
>>>> 
>>> 
>> 
> <kernel error - excerpt messages_02.txt>