Please, advise. What are we doing wrong? 2022-12-08T00:55:42.030700-06:00 hermes rsyslogd[29735]: imjournal: 90281 messages lost due to rate-limiting (20000 allowed within 10000 seconds)
2022-12-08T20:10:14.084462-06:00 hermes rsyslogd[11047]: rsyslogd[internal_messages]: 23 messages lost due to rate-limiting (500 allowed within 5 seconds) We are still rate limited (see above), although we have this active in rsyslog.conf: module(load="imjournal" Ratelimit.Interval="10000" StateFile="imjournal.state") On Tue, Dec 6, 2022 at 8:16 AM helices <[email protected]> wrote: > David, > > What am I doing wrong? > > module(load="imjournal" Ratelimit.Interval="10000" > StateFile="imjournal.state") > > 2022-12-06T07:19:26.004772-06:00 hermes rsyslogd[29735]: > rsyslogd[internal_messages]: 1755 messages lost due to rate-limiting (500 > allowed within 5 seconds) > > Please, advise. Thank you. > > ~ Mike > > > > On Thu, Dec 1, 2022 at 3:12 PM David Lang <[email protected]> wrote: > >> On Thu, 1 Dec 2022, helices wrote: >> >> > [1] What is "action() syntax?" Which lines ought to be converted? How? >> >> >> https://www.rsyslog.com/doc/master/configuration/basic_structure.html#statement-types >> >> instead of >> >> @@10.0.0.1 >> >> you would do >> >> action(type="omfwd" target="10.0.0.1" port="514" protocol="tcp") >> >> for this trivial example, the earlier syntax makes more sense, but when >> you have >> more complex things (like the queues that you have), adding them all into >> the >> action makes it clearer exactly what is happening >> >> >> so you currently have >> >> >>> $ActionName Admin >> >>> $ActionQueueDequeueSlowdown 1000 # How long (in microseconds) >> dequeueing >> >>> should be delayed >> >>> $ActionQueueFileName ZenossQueue # Set file name, also enables disk >> mode >> >>> $ActionQueueSaveOnShutdown on # Save messages to disk on shutdown >> >>> $ActionQueueType LinkedList # Use asynchronous processing >> >>> $ActionResumeRetryCount -1 # Infinite retries on insert failure >> >>> *.* @@10.199.1.160 >> >> >> This would be >> >> action(name="Admin" type="omfwd" target="10.199.1.160" protocol="tcp" >> queue.filename="ZenossQueue" queue.saveonshutdown="on" >> queue.type="linkedlist" >> resumeretrycount="-1" queue.dequeueslowdown="1000") >> >> this makes it very clear that all these parameters apply only to this >> action >> (which is what the old syntax does, but it's less obvious to people that >> it only >> applies to the next action) >> >> > [2] Where is the "pause" you mention? I don't recognize that. >> >> $ActionQueueDequeueSlowdown 1000 # How long (in microseconds) dequeueing >> >> This tells rsyslog to pause after each batch of messages before >> processing the >> next batch. >> >> > [3] impstats? Permanently? Only for this debugging? >> >> I like to have it on permanently, but especially for debugging it >> provides a lot >> of useful info >> >> > [4] How to modify imjournal rate limits? >> >> see >> https://www.rsyslog.com/doc/v8-stable/configuration/modules/imjournal.html >> >> > [5] RSYSLOG_DebugFormat? I found this: >> > https://www.rsyslog.com/doc/v8-stable/configuration/templates.html - Is >> > that example proper by itself? Where does this template go? How can I >> > specify the file and location for debugging? >> >> as I said below >> >> >> ftp.* /var/log/ftp;RSYSLOG_DebugFormat (legacy format, add >> template="RSYSLOG_DebugFormat" to that action() format) >> >> > If there are URLs to inform me, I appreciate your direction. >> >> https://www.rsyslog.com/doc/v8-stable/configuration/modules/imjournal.html >> https://www.rsyslog.com/doc/v8-stable/configuration/modules/ommysql.html >> https://www.rsyslog.com/doc/v8-stable/configuration/modules/omfwd.html >> https://www.rsyslog.com/doc/master/configuration/actions.html >> https://www.rsyslog.com/doc/master/rainerscript/queue_parameters.html >> https://www.rsyslog.com/doc/v8-stable/configuration/modules/omfile.html >> >> feel free to keep asking questions. >> >> David Lang >> >> >> > ~ Mike >> > >> > >> > >> > On Thu, Dec 1, 2022 at 1:33 PM David Lang <[email protected]> wrote: >> > >> >> it would be useful to convert to the action() syntax as it makes it >> >> clearer >> >> what's happening. >> >> >> >> Why are you pausing between writing logs? (this could be why you are >> >> dropping >> >> logs) >> >> >> >> given the number of queues and actions, look at configuring impstats so >> >> that you >> >> can see the number of messages in the queues, number processed, etc. >> >> >> >> imjournal defaults to some fairly aggressive rate limiting, I find >> that I >> >> always >> >> need to drastically increase the limits. >> >> >> >> writing logs using the RSYSLOG_DebugFormat is adding the template to >> the >> >> file >> >> >> >> ftp.* /var/log/ftp;RSYSLOG_DebugFormat (legacy format, add >> >> template="RSYSLOG_DebugFormat" to that action() format) >> >> >> >> the debug format is large, but you really need to see the message >> that's >> >> failing >> >> to figure out why it's failing. The MySQL logs may give you better >> info on >> >> that. >> >> >> >> David Lang >> >> >> >> On Thu, 1 Dec 2022, helices wrote: >> >> >> >>> Date: Thu, 1 Dec 2022 13:26:47 -0600 >> >>> From: helices <[email protected]> >> >>> To: David Lang <[email protected]> >> >>> Cc: helices via rsyslog <[email protected]> >> >>> Subject: Re: [rsyslog] Rsyslogd/ommysql.so: Not writing to DB >> >> intermittently >> >>> >> >>> Thank you. >> >>> >> >>> [1] rsyslog.conf >> >>> >> >>> # date; grep -v "^\(#\|\s*$\)" /etc/rsyslog.conf ;date >> >>> Thu Dec 1 13:19:34 CST 2022 >> >>> module(load="imjournal" StateFile="imjournal.state") >> >>> module(load="imklog") >> >>> module(load="immark") >> >>> module(load="impstats" interval="600" severity="7") >> >>> syslog.=debug /var/log/rsyslog-stats >> >>> module(load="imtcp") >> >>> input(type="imtcp" port="514") >> >>> module(load="imudp") >> >>> input(type="imudp" port="514") >> >>> module(load="ommysql.so") >> >>> global(workDirectory="/var/lib/rsyslog") >> >>> authpriv.none;cron.none;*.info;mail.none /var/log/messages >> >>> authpriv.* /var/log/secure >> >>> cron.* /var/log/cron >> >>> *.emerg :omusrmsg:* >> >>> ftp.* /var/log/vsftpd.log >> >>> local7.* /var/log/boot.log >> >>> mail.* /var/log/maillog >> >>> uucp,news.crit /var/log/spooler >> >>> $ActionName Ftp >> >>> $ActionQueueDequeueSlowdown 1000 # How long (in microseconds) >> dequeueing >> >>> should be delayed >> >>> $ActionQueueFileName dbFtpQueue # Set file name, also enables disk >> mode >> >>> $ActionQueueSaveOnShutdown on # Save messages to disk on shutdown >> >>> $ActionQueueType LinkedList # Use asynchronous processing >> >>> $ActionResumeRetryCount -1 # Infinite retries on insert failure >> >>> ftp.* >> >>> :ommysql:10.199.5.177,vsftplog,hermesvsftplog,_____ >> >>> $ActionName Sftp >> >>> $ActionQueueDequeueSlowdown 1000 # How long (in microseconds) >> >> dequeueing >> >>> should be delayed >> >>> $ActionQueueFileName dbSftpQueue # Set file name, also enables disk >> >> mode >> >>> $ActionQueueSaveOnShutdown on # Save messages to disk on shutdown >> >>> $ActionQueueType LinkedList # Use asynchronous processing >> >>> $ActionResumeRetryCount -1 # Infinite retries on insert >> failure >> >>> authpriv.* >> >>> :ommysql:10.199.5.177,sftplogDB,hermesvsftplog,_____ >> >>> $ActionName Admin >> >>> $ActionQueueDequeueSlowdown 1000 # How long (in microseconds) >> dequeueing >> >>> should be delayed >> >>> $ActionQueueFileName ZenossQueue # Set file name, also enables disk >> mode >> >>> $ActionQueueSaveOnShutdown on # Save messages to disk on shutdown >> >>> $ActionQueueType LinkedList # Use asynchronous processing >> >>> $ActionResumeRetryCount -1 # Infinite retries on insert failure >> >>> *.* @@10.199.1.160 >> >>> Thu Dec 1 13:19:34 CST 2022 >> >>> >> >>> >> >>> [2] How do we "log the message with the template RSYSLOG_DebugFormat >> to a >> >>> file?" How much disk space is needed? This problem appears to have >> >> started >> >>> recently, and appears to happen once or twice per day, without a >> common >> >>> time. >> >>> >> >>> [3] I didn't notice the rate-limiting until now. It is not uncommon. >> How >> >>> can we avoid losing so many messages? >> >>> >> >>> ~ Mike >> >>> >> >>> >> >>> On Thu, Dec 1, 2022 at 1:05 PM David Lang <[email protected]> wrote: >> >>> >> >>>> please post your full config. >> >>>> >> >>>> It would also help to log the message with the template >> >>>> RSYSLOG_DebugFormat to a >> >>>> file and find the log entry that is failing to insert. >> >>>> >> >>>> my guess is that the quotes in the message are confusing mysql >> >>>> >> >>>> note that rate limiting is throwing away messages because you are >> trying >> >>>> to >> >>>> process them too fast. >> >>>> >> >>>> David Lang >> >>>> >> >>>> On Thu, 1 Dec 2022, helices via rsyslog wrote: >> >>>> >> >>>>> Date: Thu, 1 Dec 2022 10:08:01 -0600 >> >>>>> From: helices via rsyslog <[email protected]> >> >>>>> To: rsyslog-users <[email protected]> >> >>>>> Cc: helices <[email protected]> >> >>>>> Subject: [rsyslog] Rsyslogd/ommysql.so: Not writing to DB >> >> intermittently >> >>>>> >> >>>>> # date; /bin/yum list rsyslog rsyslog-mysql ;date >> >>>>> Thu Dec 1 09:47:18 CST 2022 >> >>>>> Loaded plugins: fastestmirror >> >>>>> Loading mirror speeds from cached hostfile >> >>>>> * base: download.cf.centos.org >> >>>>> * epel: mirror.genesisadaptive.com >> >>>>> * extras: download.cf.centos.org >> >>>>> * remi-php56: mirror.pit.teraswitch.com >> >>>>> * remi-safe: mirror.pit.teraswitch.com >> >>>>> * updates: download.cf.centos.org >> >>>>> Installed Packages >> >>>>> rsyslog.x86_64 >> 8.2210.0-1.el7 >> >>>>> @rsyslog_v8 >> >>>>> rsyslog-mysql.x86_64 >> 8.2210.0-1.el7 >> >>>>> @rsyslog_v8 >> >>>>> Thu Dec 1 09:47:19 CST 2022 >> >>>>> >> >>>>> >> >>>>> Sample of numerous error messages (/var/log/messages): >> >>>>> rsyslogd[17344]: ommysql: db error (1172): Result consisted of more >> >> than >> >>>>> one row [v8.2210.0] >> >>>>> rsyslogd[17344]: The error statement was: insert into SystemEvents >> >>>>> (Message, Facility, FromHost, Priority, DeviceReportedTime, >> ReceivedAt, >> >>>>> InfoUnitID, SysLogTag) values ('close >> >>>>> "/incoming/wood.pgez.scen.11302022.sa.pgp" bytes read 0 written 2603 >> >>>>> [postauth]', 10, 'hermes', 6, '20221201081257', '20221201081257', 1, >> >>>>> 'sshd[19654]:') [v8.2210.0 try https://www.rsyslog.com/e/2218 ] >> >>>>> rsyslogd[17344]: rsyslogd[internal_messages]: 215 messages lost due >> to >> >>>>> rate-limiting (500 allowed within 5 seconds) >> >>>>> rsyslogd[17344]: action 'Sftp' (module 'ommysql.so') message lost, >> >> could >> >>>>> not be processed. Check for additional error messages before this >> one. >> >>>>> [v8.2210.0 try https://www.rsyslog.com/e/2218 ] >> >>>>> >> >>>>> >> >>>>> We have been writing all data from Internet file transfers to a >> Mysql >> >>>> table >> >>>>> for years. Recently, we began seeing intermittent errors like those >> >>>> above. >> >>>>> >> >>>>> What is happening here? >> >>>>> >> >>>>> What can we do to fix this problem? >> >>>>> >> >>>>> Please, advise. Thank you. >> >>>>> >> >>>>> ~ Mike >> >>>>> _______________________________________________ >> >>>>> rsyslog mailing list >> >>>>> https://lists.adiscon.net/mailman/listinfo/rsyslog >> >>>>> http://www.rsyslog.com/professional-services/ >> >>>>> What's up with rsyslog? Follow https://twitter.com/rgerhards >> >>>>> NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a >> >> myriad >> >>>> of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if >> you >> >>>> DON'T LIKE THAT. >> >>>>> >> >>>> >> >>> >> >> >> > >> > _______________________________________________ rsyslog mailing list https://lists.adiscon.net/mailman/listinfo/rsyslog http://www.rsyslog.com/professional-services/ What's up with rsyslog? Follow https://twitter.com/rgerhards NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT.
