Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1757343

Summary: Duplicated messages (several instances) even with WorkAroundJournalBug="on"
Product: Red Hat Enterprise Linux 7 Reporter: Renaud Métrich <rmetrich>
Component: rsyslogAssignee: Jiří Vymazal <jvymazal>
Status: CLOSED DUPLICATE QA Contact: BaseOS QE Security Team <qe-baseos-security>
Severity: high Docs Contact:
Priority: high    
Version: 7.7CC: dapospis, jvymazal, rmeggins
Target Milestone: rc   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-10-03 13:34:25 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Patchset fixing the issue none

Description Renaud Métrich 2019-10-01 10:04:19 UTC
Description of problem:

BZ #1538372 was supposed to fix duplicated messages when journal was rotating, but apparently this doesn't work at all, duplicated messages are still found in /var/log/messages, and, when journal rotation happens often, several instances of the message can be found (not only 2 instances).


Version-Release number of selected component (if applicable):

rsyslog-8.24.0-41.el7_7.1


How reproducible:

Always


Steps to Reproduce:
1. Configure rsyslog with WorkAroundJournalBug="on" and disable completely rate limiting

  /etc/systemd/journald.conf:
  RateLimitInterval=0

  /etc/rsyslog.conf
  #$ModLoad imjournal # provides access to the systemd journal
  #$IMJournalStateFile imjournal.state
  module(load="imjournal" StateFile="imjournal.state" WorkAroundJournalBug="on" Ratelimit.Interval="0" PersistStateInterval="1")

2. Send unique messages rapidly

  # for i in $(seq 1 20000); do echo $i ; logger "$i testsyslog_1"; done

3. Check result (there were 7 rotations of the journal on my system)

  # awk '/testsyslog_1/ { print $6 }' /var/log/messages | sort | uniq -c | sort -nr | head


Actual results:

  messages seen 8 times

      8 999
      8 998
      8 997
      8 996
      8 995
      8 994
      8 993
      8 992
      8 991
      8 990


Expected results:

  messages seen once only


Additional info:

This doesn't reproduce on RHEL8.0 (rsyslog-8.37.0-9.el8.x86_64) nor Upstream rsyslog recompiled on RHEL7.

So far, I found 1 bug in RHEL7.7's code:

-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------
diff -up rsyslog-8.24.0/plugins/imjournal/imjournal.c.orig rsyslog-8.24.0/plugins/imjournal/imjournal.c
--- rsyslog-8.24.0/plugins/imjournal/imjournal.c.orig	2019-10-01 10:42:09.000000000 +0200
+++ rsyslog-8.24.0/plugins/imjournal/imjournal.c	2019-10-01 10:42:16.000000000 +0200
@@ -411,7 +411,7 @@ readjournal(void)
 
 	if (cs.bWorkAroundJournalBug) {
 		/* save journal cursor (at this point we can be sure it is valid) */
-		if (sd_journal_get_cursor(j, &c)) {
+		if (!sd_journal_get_cursor(j, &c)) {
 			free(last_cursor);
 			last_cursor = c;
 		}
-------- 8< ---------------- 8< ---------------- 8< ---------------- 8< --------

With this change, only 2 instances of the same message is seen (instead of 8).
So it helps, but is not sufficient.

See attachment for "full" patch apparently fixing the issue (maybe there is too much backport there ...)

Comment 2 Renaud Métrich 2019-10-01 10:06:37 UTC
Created attachment 1621363 [details]
Patchset fixing the issue

Please review, may be too large

Comment 4 Renaud Métrich 2019-10-01 10:07:52 UTC
With the patch attached:


# for i in $(seq 1 20000); do echo $i ; logger "$i testsyslog_1"; done

# awk '/testsyslog_1/ { print $6 }' /var/log/messages | sort | uniq -c | sort -nr | head
      1 9999
      1 9998
      1 9997
      1 9996
      1 9995
      1 9994
      1 9993
      1 9992
      1 9991
      1 9990

--> NO DUP

# awk '/testsyslog_1/ { print $6 }' /var/log/messages | sort | uniq -c | sort -nr | wc -l
20000

--> NO MESSAGE LOSS