Bug 1505853 - rsyslog-8.30.0-1.fc26.x86_64 breaks $IMJournalStateFile
Summary: rsyslog-8.30.0-1.fc26.x86_64 breaks $IMJournalStateFile
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: rsyslog
Version: 26
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
Assignee: Radovan Sroka
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-10-24 11:55 UTC by Harald Reindl
Modified: 2017-11-11 03:04 UTC (History)
8 users (show)

Fixed In Version: rsyslog-8.30.0-3.fc26 rsyslog-8.30.0-3.fc25 rsyslog-8.30.0-3.fc27
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-11-01 00:08:39 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
upstream patch (2.17 KB, patch)
2017-10-25 11:28 UTC, Radovan Sroka
no flags Details | Diff


Links
System ID Private Priority Status Summary Last Updated
Github https://github.com/rsyslog rsyslog issues 1895 0 None None None 2020-09-10 16:32:19 UTC

Description Harald Reindl 2017-10-24 11:55:26 UTC Comment hidden (abuse)
Comment 1 Radovan Sroka 2017-10-24 13:47:19 UTC
Can you please share your rsyslog.conf?

Comment 2 Harald Reindl 2017-10-24 13:58:00 UTC
[root@testserver:~]$ cat rsyslog.conf 
#### MODULES ####

$ModLoad imjournal
$MainMsgQueueSize 100000
$WorkDirectory /var/lib/rsyslog
$IMJournalStateFile imjournal.state

$ModLoad ommysql

#### GLOBAL DIRECTIVES ####

$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$MaxMessageSize 4096

template(name="stdSQLformat" type="string" option.sql="on"
 string="insert into SystemEvents (DeviceReportedTime, FromHost, Message, SysLogTag) values ('%timereported:::date-mysql%', '%HOSTNAME%', '%msg%', '%syslogtag%')"
)

#### RULES ####
                                                                                                                                                                                                                   
# iptables in seperated logfile                                                                                                                                                                                    
:msg, startswith, "Firewall " -/var/log/firewall.log                                                                                                                                                               
& stop                                                                                                                                                                                                             
                                                                                                                                                                                                                   
# Ignored messages                                                                                                                                                                                                 
:msg, contains, "Forwarding to syslog missed" stop                                                                                                                                                                 
:msg, contains, "HostIF_ReadUptime" stop
:msg, contains, "smbd/service.c:942(make_connection_snum)" stop
:msg, contains, "Warning:[sql] dbmysql.c,db_get_result(+215): result set is null" stop
:msg, contains, "Can't become connected user" stop
:msg, contains, "util_sock.c:1432(get_peer_addr_internal)" stop
:msg, contains, "getpeername failed. Error was Der Socket ist nicht verbunden" stop
:msg, contains, "read_fd_with_timeout: client 0.0.0.0 read error = Keine Route zum Zielrechner" stop
:msg, contains, "FILTER barracudafeed" stop
:msg, contains, "uid=0 from=<root>" stop
:msg, contains, "RCPT from barracuda.thelounge.net" stop
:msg, contains, "): disconnecting" stop
:msg, contains, "lmtp_handle_connection" stop
:msg, contains, "Warning:[sql] dbmysql.c,db_get_result(+215): result set is null" stop
:msg, contains, "dbmail-imapsession.c,dbmail_imap_session_printf(+1517): write to client socket failed" stop
:msg, contains, "dbmail-imapsession.c,dbmail_imap_session_readln(+1587): timeout occurred in dbmail_imap_session_readln" stop
:msg, contains, "pop3_handle_connection(+201): client timed out, connection closed" stop
:msg, contains, "maximum number of connections reached, stopping now" stop
:msg, contains, "Asked to create mailbox which already exists" stop
:msg, contains, "connect from thx1138.thelounge.net[10.0.0.30]" stop
:msg, contains, "connect from unknown[10.0.0.30]" stop
:msg, contains, "connect from barracuda.thelounge.net[10.0.0.20]" stop
:msg, contains, "connect from unknown[10.0.0.20]" stop
:msg, contains, "connect from arrakis.thelounge.net[10.0.0.6]" stop
:msg, contains, "connect from unknown[10.0.0.6]" stop
:msg, contains, "connect from prometheus.thelounge.net[10.0.0.32]" stop
:msg, contains, "connect from unknown[10.0.0.32]" stop
:msg, contains, "connect from thebe.thelounge.net[10.0.0.38]" stop
:msg, contains, "connect from unknown[10.0.0.38]" stop
:msg, contains, "connect from localhost[127.0.0.1]" stop
:msg, contains, "connect from unknown[127.0.0.1]" stop
:msg, contains, "disconnect from thx1138.thelounge.net[10.0.0.30]" stop
:msg, contains, "disconnect from unknown[10.0.0.30]" stop
:msg, contains, "disconnect from barracuda.thelounge.net[10.0.0.20]" stop
:msg, contains, "disconnect from unknown[10.0.0.20]" stop
:msg, contains, "disconnect from arrakis.thelounge.net[10.0.0.6]" stop
:msg, contains, "disconnect from unknown[10.0.0.6]" stop
:msg, contains, "disconnect from prometheus.thelounge.net[10.0.0.32]" stop
:msg, contains, "disconnect from unknown[10.0.0.32]" stop
:msg, contains, "disconnect from thebe.thelounge.net[10.0.0.38]" stop
:msg, contains, "disconnect from unknown[10.0.0.38]" stop
:msg, contains, "disconnect from localhost[127.0.0.1]" stop
:msg, contains, "disconnect from unknown[127.0.0.1]" stop
:msg, contains, "lost connection after CONNECT from thx1138.thelounge.net[10.0.0.30]" stop
:msg, contains, "lost connection after CONNECT from unknown[10.0.0.30]" stop
:msg, contains, "lost connection after CONNECT from barracuda.thelounge.net[10.0.0.20]" stop
:msg, contains, "lost connection after CONNECT from unknown[10.0.0.20]" stop
:msg, contains, "lost connection after CONNECT from arrakis.thelounge.net[10.0.0.6]" stop
:msg, contains, "lost connection after CONNECT from unknown[10.0.0.6]" stop
:msg, contains, "lost connection after CONNECT from prometheus.thelounge.net[10.0.0.32]" stop
:msg, contains, "lost connection after CONNECT from unknown[10.0.0.32]" stop
:msg, contains, "lost connection after CONNECT from thebe.thelounge.net[10.0.0.38]" stop
:msg, contains, "lost connection after CONNECT from unknown[10.0.0.38]" stop
:msg, contains, "lost connection after CONNECT from localhost[127.0.0.1]" stop
:msg, contains, "lost connection after CONNECT from unknown[127.0.0.1]" stop
:msg, contains, "Did not receive identification string from thx1138.thelounge.net[10.0.0.30]" stop
:msg, contains, "Did not receive identification string from unknown[10.0.0.30]" stop
:msg, contains, "Did not receive identification string from barracuda.thelounge.net[10.0.0.20]" stop
:msg, contains, "Did not receive identification string from unknown[10.0.0.20]" stop
:msg, contains, "Did not receive identification string from arrakis.thelounge.net[10.0.0.6]" stop
:msg, contains, "Did not receive identification string from unknown[10.0.0.6]" stop
:msg, contains, "Did not receive identification string from prometheus.thelounge.net[10.0.0.32]" stop
:msg, contains, "Did not receive identification string from unknown[10.0.0.32]" stop
:msg, contains, "Did not receive identification string from thebe.thelounge.net[10.0.0.38]" stop
:msg, contains, "Did not receive identification string from unknown[10.0.0.38]" stop
:msg, contains, "Did not receive identification string from localhost[127.0.0.1]" stop
:msg, contains, "Did not receive identification string from unknown[127.0.0.1]" stop
:msg, contains, "selinux sandbox not useful" stop
:msg, contains, "DHCPREQUEST on eth" stop
:msg, contains, "/etc/ssh/ssh_host_ecdsa_key" stop
:msg, contains, "Vacuuming done, freed" stop
:msg, contains, "interface=\"org.freedesktop.login1.Manager\" member=\"ReleaseSession\"" stop
:msg, contains, "automatic empty zone" stop
:msg, contains, "Failed to mark scope session" stop
:msg, contains, "Failed to open private bus connection" stop
:msg, contains, "udisks2.service" stop
:msg, contains, "upower.service" stop
:msg, contains, "Failed at step CGROUP spawning /usr/lib/systemd/systemd" stop
:msg, contains, "Starting Letsencrypt-Updateservice" stop
:msg, contains, "Started Letsencrypt-Updateservice" stop

# supress dovecot-warning
:msg, contains, "Error: stats: open(stats-user) failed: No such file or directory" stop

# Spamfirewall
:msg, contains, "replace: header X-Virus-Scanned" stop
:msg, contains, "prefork: child states: " stop
:msg, contains, "setuid to sa-milt succeeded" stop
:msg, contains, "Could not extract score from <>" stop
:msg, contains, "Increasing spamd children: " stop
:msg, contains, "Decreasing spamd children: " stop
:msg, contains, "spamd: connection from localhost" stop
:msg, contains, "spamd: cannot send SIGINT to child process" stop
:msg, contains, "spamd: server successfully spawned child process" stop
:msg, contains, "spamd: restarting using '/usr/bin/spamd" stop
:msg, contains, "Please add it to confMILTER_MACROS_CONNECT" stop
:msg, contains, "Please add it to confMILTER_MACROS_ENVFROM" stop
:msg, contains, "killed successfully: interrupted, signal 2 (0002)" stop
:msg, contains, "Reloading Spamassassin Daemon" stop
:msg, contains, "Reloaded Spamassassin Daemon" stop
:msg, contains, "Reloading Postfix MTA" stop
:msg, contains, "Reloaded Postfix MTA" stop
:msg, contains, "bayes db update ignored: Read-only file system" stop
:msg, contains, "bayes: locker: safe_lock: cannot create tmp lockfile" stop

# supress new systemd-crap starting with F22
:msg, contains, "ignoring: Unit cryptsetup.target is masked" stop
:msg, contains, "ignoring: Unit swap.target is masked" stop
:msg, contains, "ignoring: Unit dnf-makecache.timer is masked" stop

# supress "su: (to wwwcron) root on none" messages starting with Fedora 19
:msg, contains, "(to wwwcron) root on" stop
:msg, contains, "(to clamupdate) root on" stop
:msg, contains, "(to sa-milt) root on" stop

# log all postgrey messages into maillog
:programname, isequal, "postgrey"                   -/var/log/maillog
:programname, isequal, "postgrey" stop

# log dhcpd in own file
:programname, isequal, "dhcpd"                      -/var/log/dhcpd.log
:programname, isequal, "dhcpd" stop

# dracut messages not in /var/log/messages (Fedora 20)
:programname, isequal, "dracut"                     -/var/log/dracut.log
:programname, isequal, "dracut" stop

# do not log 'yum' in /var/log/yum.log AND /var/log/messages
:programname, isequal, "yum" stop

# do not log systemd-reloads
:msg, contains, "Reloading\." stop

# do not log failed starts of masked services
:msg, contains, "Unit upower.service is masked" stop

# systemd slice spam
:msg, startswith, "Closed D-Bus User Message Bus Socket" stop
:msg, startswith, "Created slice User Slice of harry" stop
:msg, startswith, "Listening on D-Bus User Message Bus Socket" stop
:msg, startswith, "Removed slice User Slice of harry" stop
:msg, startswith, "Starting D-Bus User Message Bus Socket" stop

# drop most systemd-session-log and move remaining to /var/log/secure
if $programname == 'systemd' or $programname == 'systemd-logind' then {
 if $syslogseverity == 6 then {
  :msg, startswith, "Starting Session" stop
  :msg, startswith, "Started Session" stop
  :msg, startswith, "Stopping Session" stop
  :msg, startswith, "Stopped Session" stop
  :msg, startswith, "New session" stop
  :msg, startswith, "Removed session" stop
  :msg, startswith, "Starting Paths" stop
  :msg, startswith, "Reached target Paths" stop
  :msg, startswith, "Starting Timers" stop
  :msg, startswith, "Reached target Timers" stop
  :msg, startswith, "Starting Sockets" stop
  :msg, startswith, "Reached target Sockets" stop
  :msg, startswith, "Starting Basic System" stop
  :msg, startswith, "Reached target Basic System" stop
  :msg, startswith, "Starting Default" stop
  :msg, startswith, "Reached target Default" stop
  :msg, startswith, "Startup finished" stop
  :msg, startswith, "Stopping Default" stop
  :msg, startswith, "Stopped target Default" stop
  :msg, startswith, "Stopping Basic System" stop
  :msg, startswith, "Stopped target Basic System" stop
  :msg, startswith, "Stopping Paths" stop
  :msg, startswith, "Stopped target Paths" stop
  :msg, startswith, "Stopping Timers" stop
  :msg, startswith, "Stopped target Timers" stop
  :msg, startswith, "Stopping Sockets" stop
  :msg, startswith, "Stopped target Sockets" stop
  :msg, startswith, "Starting Shutdown" stop
  :msg, startswith, "Reached target Shutdown" stop
  :msg, startswith, "Starting Exit the Session" stop
  :msg, startswith, "Received SIGRTMIN" stop
  :msg, startswith, "Failed to abandon session scope" stop
  :msg, startswith, "Starting user-" stop
  :msg, startswith, "Created slice user-" stop
  :msg, startswith, "Starting User Manager for" stop
  :msg, startswith, "Started User Manager for" stop
  :msg, startswith, "Stopping User Manager for" stop
  :msg, startswith, "Stopped User Manager for" stop
  :msg, startswith, "Stopping user-" stop
  :msg, startswith, "Removed slice user-" stop
 }
 :programname, isequal, "systemd-logind" -/var/log/secure
 :programname, isequal, "systemd-logind" stop
}

# Include config snippets
$IncludeConfig /etc/rsyslog.d/

# Log anything (except mail) of level info or higher
# Don't log private authentication messages
*.info;mail.none;authpriv.none;cron.none            -/var/log/messages

# The authpriv file has restricted access
authpriv.*                                          -/var/log/secure

# Log all the mail messages in one place
mail.*                                              -/var/log/maillog

# Log cron stuff
cron.*                                              -/var/log/cron

# Everybody gets emergency messages
*.emerg                                             :omusrmsg:*

# Save news errors of crit in special file
uucp,news.crit                                      -/var/log/spooler

# Save boot messages also to boot.log
local7.*                                            -/var/log/boot.log

### DATABASE-LOGGING ###

$ActionQueueType LinkedList                         # use asynchronous processing
$ActionResumeRetryCount -1                          # infinite retries on insert failure
*.info;mail.none;authpriv.none;cron.none            action(type="ommysql" server="192.168.196.2" serverport="3306" db="dbmail" uid="vm_syslog" pwd="****" template="stdSQLformat")
mail.*                                              action(type="ommysql" server="127.0.0.1" serverport="3307" db="rsyslog" uid="rsyslog" pwd="****" template="stdSQLformat")
[root@testserver:~]$

Comment 3 Radovan Sroka 2017-10-25 11:28:57 UTC
Created attachment 1343177 [details]
upstream patch

patch that resolves bug in broken imjournal module

Comment 4 Fedora Update System 2017-10-25 12:04:00 UTC
rsyslog-8.30.0-3.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2017-7b82052b7d

Comment 5 Fedora Update System 2017-10-25 12:05:05 UTC
rsyslog-8.30.0-3.fc26 has been submitted as an update to Fedora 26. https://bodhi.fedoraproject.org/updates/FEDORA-2017-7bc779b07b

Comment 6 Fedora Update System 2017-10-25 12:08:58 UTC
rsyslog-8.30.0-3.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2017-dde64835b4

Comment 7 Fedora Update System 2017-10-26 01:11:53 UTC
rsyslog-8.30.0-3.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-dde64835b4

Comment 8 Fedora Update System 2017-10-26 01:33:54 UTC
rsyslog-8.30.0-3.fc26 has been pushed to the Fedora 26 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-7bc779b07b

Comment 9 Fedora Update System 2017-10-26 10:47:10 UTC
rsyslog-8.30.0-3.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2017-7b82052b7d

Comment 10 Fedora Update System 2017-10-27 11:05:23 UTC
rsyslog-8.30.0-3.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2017-7b82052b7d

Comment 11 Fedora Update System 2017-10-27 18:47:56 UTC
rsyslog-8.30.0-3.fc27 has been pushed to the Fedora 27 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-7b82052b7d

Comment 12 Fedora Update System 2017-11-01 00:08:39 UTC
rsyslog-8.30.0-3.fc26 has been pushed to the Fedora 26 stable repository. If problems still persist, please make note of it in this bug report.

Comment 13 Andrew Haveland-Robinson 2017-11-01 12:38:18 UTC
Upgraded from
rsyslog-8.27.0-1.fc26.x86_64 to
rsyslog-8.30.0-3.fc26.x86_64 today.

It would not restart, giving this error in /var/log/messages:
rsyslogd: could not load module '/usr/lib64/rsyslog/lmnsd_ptcp.so', rsyslog error -2054  [v8.29.0 try http://www.rsyslog.com/e/2068 ]

Turned out this was related to rsyslog-gnutls, which I have never used and wasn't installed as a new dependency, however after installing it, rsyslog would still not restart.
I updated rsyslog.conf with the rpmnew version, and would still not restart and could not find any reason why not.
jouronalctl -xe just gives useless errors:
rsyslog.service: Unit entered failed state.
rsyslog.service: Failed with result 'exit-code'.

I've given up and downgraded back to rsyslog-8.27.0-1 which works.

Comment 14 Radovan Sroka 2017-11-01 12:41:38 UTC
(In reply to Andrew Haveland-Robinson from comment #13)
> Upgraded from
> rsyslog-8.27.0-1.fc26.x86_64 to
> rsyslog-8.30.0-3.fc26.x86_64 today.
> 
> It would not restart, giving this error in /var/log/messages:
> rsyslogd: could not load module '/usr/lib64/rsyslog/lmnsd_ptcp.so', rsyslog
> error -2054  [v8.29.0 try http://www.rsyslog.com/e/2068 ]
> 
> Turned out this was related to rsyslog-gnutls, which I have never used and
> wasn't installed as a new dependency, however after installing it, rsyslog
> would still not restart.
> I updated rsyslog.conf with the rpmnew version, and would still not restart
> and could not find any reason why not.
> jouronalctl -xe just gives useless errors:
> rsyslog.service: Unit entered failed state.
> rsyslog.service: Failed with result 'exit-code'.
> 
> I've given up and downgraded back to rsyslog-8.27.0-1 which works.

Just for sure, take a look on this bugzilla: https://bugzilla.redhat.com/show_bug.cgi?id=1508359

Comment 15 Andrew Haveland-Robinson 2017-11-01 14:26:17 UTC
Thanks Radovan,

dnf update libfastjson --enablerepo=updates-testing

did indeed fix the problem. Logging is being replicated to my syslog server using my old rsyslog.conf

(I tried to use rsyslog.conf.rpmnew, but got no output and no forwarding, so this is something else I'll have to look into, but the old conf at least works).

After spending some time upgrading and downgrading rsyslog from about 10 servers, it would have been good if this could have been caught earlier before publishing to the stable repo!

Comment 16 Harald Reindl 2017-11-01 14:43:19 UTC Comment hidden (abuse)
Comment 17 Andrew Haveland-Robinson 2017-11-01 15:44:56 UTC
No harm done Radovan, none are mission critical production servers.
I have created local repos in the past but it's wasteful keeping a repository of stuff that'll never be used.

Instead I simply share /var/cache/dnf over nfs, and update them sequentially (because dnf has no concurrency) and then keep the cache for the next machine. There is room for improvement here if the authors would consider it.

Mirroring becomes moot, because once a package is in the cache, mirrors and duplicate downloading are no longer required, and it can be purged afterwards.

I just didn't spot the rsyslog error until a couple of hours later, when services I wrote that tail the messages and maillog to extract info for banning intrusion attempts went unusually quiet.

I accept that occasionally there are errors in packaging, but there is always a solution, and thank you again.

Comment 18 Harald Reindl 2017-11-01 17:00:20 UTC Comment hidden (abuse)
Comment 19 Fedora Update System 2017-11-06 23:33:02 UTC
rsyslog-8.30.0-3.fc25 has been pushed to the Fedora 25 stable repository. If problems still persist, please make note of it in this bug report.

Comment 20 Fedora Update System 2017-11-11 03:04:56 UTC
rsyslog-8.30.0-3.fc27 has been pushed to the Fedora 27 stable repository. If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.