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 1538372 - rsyslog appears to duplicate messages from journald when journald rotates its log files
Summary: rsyslog appears to duplicate messages from journald when journald rotates its...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: rsyslog
Version: 7.4
Hardware: All
OS: Linux
urgent
high
Target Milestone: rc
: ---
Assignee: Jiří Vymazal
QA Contact: Dalibor Pospíšil
URL:
Whiteboard:
Depends On:
Blocks: 1477664 1543992 1544394 1545580 1545582
TreeView+ depends on / blocked
 
Reported: 2018-01-24 23:53 UTC by Peter Portante
Modified: 2021-12-10 15:36 UTC (History)
23 users (show)

Fixed In Version: rsyslog-8.24.0-30.el7
Doc Type: Bug Fix
Doc Text:
Cause: Journald rotating log files Consequence: Rsyslog duplicating messages Fix: use module(load="imjournal" StateFile="imjournal.state" WorkAroundJournalBug="on") instead of default. Result: Messages are not duplicated anymore. Be aware that there is risk of performance impact while using this option.
Clone Of:
: 1543992 1544394 1545580 1545582 (view as bug list)
Environment:
Last Closed: 2018-10-30 10:17:00 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github rsyslog rsyslog issues 2436 0 'None' closed imjournal does not appear to follow the journal correctly when the journal rotates 2021-02-12 12:42:42 UTC
Github rsyslog rsyslog pull 2437 0 'None' closed Fix to reloading journal 2021-02-12 12:42:42 UTC
Github rsyslog rsyslog pull 2543 0 'None' closed Fetching cursor on readJournal() and simplified pollJournal() 2021-02-12 12:42:42 UTC
Github systemd systemd issues 7998 0 'None' closed Shouldn't a "journalctl -f" use the proper sd_journal_*() APIs to handle file rotation as documented? 2021-02-12 12:42:44 UTC
Red Hat Bugzilla 1632211 0 urgent CLOSED sd_journal_get_cursor() failed - when time is changed 2023-10-06 17:55:46 UTC
Red Hat Bugzilla 1634536 0 unspecified CLOSED rsyslog generate duplicated messages with '$ImjournalIgnorePreviousMessages on' 2022-03-13 15:39:17 UTC
Red Hat Knowledge Base (Solution) 3610971 0 None None None 2018-09-24 11:44:46 UTC
Red Hat Product Errata RHEA-2018:3135 0 None None None 2018-10-30 10:19:08 UTC

Internal Links: 1632211 1634536

Description Peter Portante 2018-01-24 23:53:50 UTC 
Description of problem:

    When the journal rotates only new logs from the
    previous location spot in the journal should be
    collected when the journal is re-opened.  Instead,
    it appears that certain logs are re-read and
    appear as duplicates in the rsyslog output.

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

    rsyslogd 8.24.0, compiled with:
	PLATFORM:				x86_64-redhat-linux-gnu
	PLATFORM (lsb_release -d):
	FEATURE_REGEXP:				Yes
	GSSAPI Kerberos 5 support:		Yes
	FEATURE_DEBUG (debug build, slow code):	No
	32bit Atomic operations supported:	Yes
	64bit Atomic operations supported:	Yes
	memory allocator:			system default
	Runtime Instrumentation (slow code):	No
	uuid support:				Yes
	Number of Bits in RainerScript integers: 64

How reproducible:

    Fairly easily with the right logging rate for a
    journald configuration to cause the journal files
    to rotate.

Steps to Reproduce:

    1. Create unique log messages flowing through
       journal periodically
    2. Place a load on journald that will cause sufficient
       logs to be collected to cause rotation
    3. Observe the output of logs where ever rsyslog is
       directed to send them (files, or otherwise, or both)

Actual results:

    Duplicates appear in all output methods configured.

Expected results:

    No duplicates are seen in any output method.
Comment 3 Peter Portante 2018-01-25 12:38:24 UTC 
I have what appears to be solution to this bug that I am testing in a standalone program and will post shortly once I clean it up.

This fix is basically fetching the cursor before the sd_journal_get_fd/sd_journal_process calls, from what I can tell.

I am going to open a systemd issue regarding this to be sure this is the proper method to tail the journal continually.
Comment 4 Peter Portante 2018-01-25 14:57:00 UTC 
Here is an example C program of what appears to be the proper sequence to tail the journal: https://gist.github.com/portante/ff7fb429c6f973aab377f7bb77b0ffdb
Comment 5 Peter Portante 2018-01-27 18:33:32 UTC 
The fix is to NOT reload the journal, but be sure to create the inotify file descriptor via the sd_journal_get_fd() API immediately after sd_journal_open() is called.  See the attached systemd issue, 7998 for more details.

A patch upstream has been proposed for rsyslog at: https://github.com/rsyslog/rsyslog/pull/2437
Comment 8 xuefeng liu 2018-02-01 08:17:51 UTC 
Changing the status is for testing the Jira syncing plugin
Comment 10 Peter Portante 2018-02-07 17:26:12 UTC 
Upstream patch has been merged!
Comment 46 Peter Portante 2018-03-07 03:06:33 UTC 
Has the updated patch with the regression removed been proposed upstream yet?

I still have some reservations about this patch, in particular that it is arguably covering up a problem the should be solved by the systemd APIs themselves, and it proposes add a call to fetch the cursor after every log entry is fetched (which might be a performance impact (I'll be measuring that shortly)).
Comment 50 Rich Megginson 2018-03-14 16:09:57 UTC 
you could also submit this patch as a pull request at https://gitlab.cee.redhat.com/rsyslog/rsyslog
Comment 53 Jiří Vymazal 2018-03-15 08:19:06 UTC 
(In reply to Rich Megginson from comment #50)
> you could also submit this patch as a pull request at
> https://gitlab.cee.redhat.com/rsyslog/rsyslog

https://gitlab.cee.redhat.com/rsyslog/rsyslog/merge_requests/1
Comment 68 masanari iida 2018-09-12 11:24:08 UTC 
currently https://access.redhat.com/site/solutions/3339431 is 
linked in "External trackers".
But I think this KB is not related to this symptom.

I think https://access.redhat.com/solutions/3610971 
( rsyslog logging duplicate logs during retention timing )
should be the correct KB.

Please update external tracker link.
Thanks
Comment 71 errata-xmlrpc 2018-10-30 10:17:00 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2018:3135
Note You need to log in before you can comment on or make changes to this bug.