Red Hat Bugzilla – 2010947 – journalctl -f with MESSAGE_ID= before messages with that ID exist in the journal results in "buffered" output of future messages
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.
Description of problem:
We were using "journalctl -f" in the OpenShift MCO operator to watch for login events and we noticed that we don't get any (I suspect because we don't ever reach 50+ logins to a RHCOS box)
If you:
- run "journalctl -f" with a MESSAGE_ID= AND
- there are no matching log messages already in the journal at the time the command is run
Then:
- once messages with that MESSAGE_ID do exist, you will not receive them until some number/amount/size of them accumulate
Version-Release number of selected component (if applicable):
systemd 239 (239-45.el8_4.2) on RHCOS
systemd 248 (v248.7-1.fc34) on FCOS
How reproducible:
Every time.
Steps to Reproduce:
1. Create a unit that logs filtered logs to a text file:
sudo cat << EOF > /etc/systemd/system/early_listen.service
[Unit]
Description=Hang journalctl before anyone logs in by filtering both unit and message id
Before=network-online.target
[Service]
User=root
ExecStart=/bin/sh -c "journalctl -b -f -o cat -u systemd-logind.service MESSAGE_ID=8d45620c1a4348dbb17410da57c60c66 | tee /tmp/journal_unit_messageid.txt"
[Install]
WantedBy=multi-user.target
EOF
2.) Enable that unit
systemctl enable early_listen
3.) Clear your journal:
sudo journalctl --flush
sudo journalctl --vacuum-time=1s
4.) Restart your server (may be able to get by without rebooting, I just always did)
sudo systemctl reboot
5.) When the server comes back up, login/ssh into the server
ssh core.122.16
6.) observe that /tmp/journal_unit_messageid.txt is still empty
cat /tmp/journal_unit_messageid.txt
7.) if you repeatedly login in a loop, after some number of logins (usually > 50) it will snap out of it and events start coming out immediately
Actual results:
Messages do not come out until some unseen/unknown threshold is met
Expected results:
Messages come out as they occur
Additional info:
- It *feels* like buffering, and at first I thought it was standard output buffering and I was doing something wrong, but after testing I don't think so. I also ran it with "stdbuf" for good measure and it didn't help.
- If MESSAGE_ID is omitted, journalctl works as expected and messages are returned immediately
- Any "journalctl -f" process started *after* a login message is present in the journal does return (and continue to return) events immediately
- It does not appear to be time based -- the messages do not seem to come out after days or hours, the only time they start coming out again is when there seem to be "enough of them"
I cannot reproduce this. I tried to run journalctl both manually and via a service, with and without tee, but I haven't seen any delay in the output.
Comment 4RHEL Program Management
2023-09-21 11:09:17 UTC
Issue migration from Bugzilla to Jira is in process at this time. This will be the last message in Jira copied from the Bugzilla bug.
Comment 5RHEL Program Management
2023-09-21 11:14:20 UTC
This BZ has been automatically migrated to the issues.redhat.com Red Hat Issue Tracker. All future work related to this report will be managed there.
Due to differences in account names between systems, some fields were not replicated. Be sure to add yourself to Jira issue's "Watchers" field to continue receiving updates and add others to the "Need Info From" field to continue requesting information.
To find the migrated issue, look in the "Links" section for a direct link to the new issue location. The issue key will have an icon of 2 footprints next to it, and begin with "RHEL-" followed by an integer. You can also find this issue by visiting https://issues.redhat.com/issues/?jql= and searching the "Bugzilla Bug" field for this BZ's number, e.g. a search like:
"Bugzilla Bug" = 1234567
In the event you have trouble locating or viewing this issue, you can file an issue by sending mail to rh-issues. You can also visit https://access.redhat.com/articles/7032570 for general account information.
Description of problem: We were using "journalctl -f" in the OpenShift MCO operator to watch for login events and we noticed that we don't get any (I suspect because we don't ever reach 50+ logins to a RHCOS box) If you: - run "journalctl -f" with a MESSAGE_ID= AND - there are no matching log messages already in the journal at the time the command is run Then: - once messages with that MESSAGE_ID do exist, you will not receive them until some number/amount/size of them accumulate Version-Release number of selected component (if applicable): systemd 239 (239-45.el8_4.2) on RHCOS systemd 248 (v248.7-1.fc34) on FCOS How reproducible: Every time. Steps to Reproduce: 1. Create a unit that logs filtered logs to a text file: sudo cat << EOF > /etc/systemd/system/early_listen.service [Unit] Description=Hang journalctl before anyone logs in by filtering both unit and message id Before=network-online.target [Service] User=root ExecStart=/bin/sh -c "journalctl -b -f -o cat -u systemd-logind.service MESSAGE_ID=8d45620c1a4348dbb17410da57c60c66 | tee /tmp/journal_unit_messageid.txt" [Install] WantedBy=multi-user.target EOF 2.) Enable that unit systemctl enable early_listen 3.) Clear your journal: sudo journalctl --flush sudo journalctl --vacuum-time=1s 4.) Restart your server (may be able to get by without rebooting, I just always did) sudo systemctl reboot 5.) When the server comes back up, login/ssh into the server ssh core.122.16 6.) observe that /tmp/journal_unit_messageid.txt is still empty cat /tmp/journal_unit_messageid.txt 7.) if you repeatedly login in a loop, after some number of logins (usually > 50) it will snap out of it and events start coming out immediately Actual results: Messages do not come out until some unseen/unknown threshold is met Expected results: Messages come out as they occur Additional info: - It *feels* like buffering, and at first I thought it was standard output buffering and I was doing something wrong, but after testing I don't think so. I also ran it with "stdbuf" for good measure and it didn't help. - If MESSAGE_ID is omitted, journalctl works as expected and messages are returned immediately - Any "journalctl -f" process started *after* a login message is present in the journal does return (and continue to return) events immediately - It does not appear to be time based -- the messages do not seem to come out after days or hours, the only time they start coming out again is when there seem to be "enough of them"