MonitorWare Knowledge Base

Hi folks,

I'm starting to see this error message on the logserver's logfile:
---
2009-04-24T06:57:49.007966-04:00 logserver rsyslogd-2079: too many tcp sessions - dropping incoming request [try http://www.rsyslog.com/e/2079
---

Browsing to the proposed URL gets redirected to kbeventdb-list-1-Adiscon-rsyslog-rsyslogd-2079.html and yields in the following:
---
Error, could not find any events with these filters.
---

Just checked the PID 2079, just in case...
---
# ps -ef | grep 2079
68 2079 2069 0 Apr08 ? 00:00:00 hald-addon-keyboard: listening on /dev/input/event2
---

Any ideas on how to solve this?? It's rsyslog-3.20.4-1 running on RHEL5


Thanks,
Martin

• Custom written rsyslog.conf?
• Maintenance Contract?
• Installation support?

I guess this is your problem:

http://bugzilla.adiscon.com/show_bug.cgi?id=122

So the solution is to upgrade.

hmm.. if I update only the server, will the rsyslog-3.19.7 clients be fully compatible and won't cause any harm?

cheers,
Martin

They should not have any problems, but obviously they are outdated and missing a couple of patches (aka "I am sure it runs, but don't complain to me if it does not ").

Rainer

Hi,

upgraded to the latest stable release 3.22
--
# rsyslogd -v
rsyslogd 3.22.0, compiled with:
FEATURE_REGEXP: Yes
FEATURE_LARGEFILE: Yes
FEATURE_NETZIP (message compression): Yes
GSSAPI Kerberos 5 support: No
FEATURE_DEBUG (debug build, slow code): Yes
Atomic operations supported: No
Runtime Instrumentation (slow code): No

See http://www.rsyslog.com for more information.
--

...but still see the same error message:
--
2009-04-27T11:53:05.470959-04:00 logserver rsyslogd-2079: too many tcp sessions - dropping incoming request [try http://www.rsyslog.com/e/2079 ]
--

Any ideas now?


Cheers,
Martin

So it now it is time for a debug log: http://www.rsyslog.com/doc-troubleshoot.html

I am interested in the first 100 lines or so before this error is first seen in the debug log.

Rainer

oops... I see "atomic operations supported: no". This is dangerous. Is your gcc outdated? (It has nothing to do with the tcp connections, but can result in "interesting" instabilities... Just a side-note.

I stopped the running process and then run this:

# /sbin/rsyslogd -c3 -f /etc/rsyslog.conf -N1 | tee rsyslog_debug.log
rsyslogd: version 3.22.0, config validation run (level 1), master config /etc/rsyslog.conf
rsyslogd: End of config validation run. Bye.

# ls -l rsyslog_debug.log
-rw-r--r-- 1 root root 0 Apr 27 12:07 rsyslog_debug.log


...not very useful, I guess...


Martin

Please read the instructions in detail. There are several troubleshooting cases defined, I need the debug log, not a config validation run

oops! my bad...

Here are the 100 first lines, as requested. Should you need more, please let me know:
--
8992.224914381:main thread: Writing pidfile /var/run/rsyslogd.pid.
8992.225260515:main thread: rsyslog 3.22.0 - called init()
8992.225289569:main thread: Unloading non-static modules.
8992.225307448:main thread: module lmnet NOT unloaded because it still has a refcount of 3
8992.225323372:main thread: Clearing templates.
8992.225403829:main thread: cfline: '$ModLoad immark.so # provides --MARK-- message capability'
8992.225465849:main thread: Requested to load module 'immark.so'
8992.225488477:main thread: loading module '/usr/lib/rsyslog/immark.so'
8992.225577036:main thread: module of type 0 being loaded.
8992.225598547:main thread: cfline: '$ModLoad imuxsock.so # provides support for local system logging (e.g. via logger command)'
8992.225618103:main thread: Requested to load module 'imuxsock.so'
8992.225635144:main thread: loading module '/usr/lib/rsyslog/imuxsock.so'
8992.225729291:main thread: imuxsock version 3.22.0 initializing
8992.225768960:main thread: module of type 0 being loaded.
8992.225787399:main thread: cfline: '$ModLoad imklog.so # provides kernel logging support (previously done by rklogd)'
8992.225806395:main thread: Requested to load module 'imklog.so'
8992.225823157:main thread: loading module '/usr/lib/rsyslog/imklog.so'
8992.225982675:main thread: module of type 0 being loaded.
8992.226004186:main thread: cfline: '$ModLoad imudp.so # provides UDP syslog reception'
8992.226022624:main thread: Requested to load module 'imudp.so'
8992.226039107:main thread: loading module '/usr/lib/rsyslog/imudp.so'
8992.226130460:main thread: source file imudp.c requested reference for module 'lmnet', reference count now 4
8992.226157837:main thread: module of type 0 being loaded.
8992.226175996:main thread: cfline: '$ModLoad imtcp.so # load module'
8992.226200022:main thread: Requested to load module 'imtcp.so'
8992.226471006:main thread: loading module '/usr/lib/rsyslog/imtcp.so'
8992.226575768:main thread: source file imtcp.c requested reference for module 'lmnet', reference count now 5
8992.226599235:main thread: caller requested object 'netstrm', not found (iRet -3003)
8992.226630803:main thread: Requested to load module 'lmnetstrms'
8992.226649241:main thread: loading module '/usr/lib/rsyslog/lmnetstrms.so'
8992.226768251:main thread: module of type 2 being loaded.
8992.226790041:main thread: source file imtcp.c requested reference for module 'lmnetstrms', reference count now 1
8992.226809876:main thread: caller requested object 'tcps_sess', not found (iRet -3003)
8992.226826079:main thread: Requested to load module 'lmtcpsrv'
8992.226842841:main thread: loading module '/usr/lib/rsyslog/lmtcpsrv.so'
8992.226945369:main thread: source file tcps_sess.c requested reference for module 'lmnetstrms', reference count now 2
8992.226976378:main thread: source file tcpsrv.c requested reference for module 'lmnet', reference count now 6
8992.226996492:main thread: source file tcpsrv.c requested reference for module 'lmnetstrms', reference count now 3
8992.227020518:main thread: module of type 2 being loaded.
8992.227038956:main thread: source file imtcp.c requested reference for module 'lmtcpsrv', reference count now 1
8992.227058232:main thread: source file imtcp.c requested reference for module 'lmtcpsrv', reference count now 2
8992.227092035:main thread: module of type 0 being loaded.
8992.227111870:main thread: cfline: '*.info;mail.none;authpriv.none;cron.none -/var/log/messages'
8992.227129750:main thread: - traditional PRI filter
8992.227146791:main thread: symbolic name: info ==> 6
8992.227175286:main thread: symbolic name: none ==> 16
8992.227199033:main thread: symbolic name: mail ==> 16
8992.227220823:main thread: symbolic name: none ==> 16
8992.227242334:main thread: symbolic name: authpriv ==> 80
8992.227263845:main thread: symbolic name: none ==> 16
8992.227285077:main thread: symbolic name: cron ==> 72
8992.227343744:main thread: tried selector action for builtin-file: 0
8992.227363299:main thread: Module builtin-file processed this config line.
8992.227391236:main thread: template: 'RSYSLOG_FileFormat' assigned
8992.227471694:main thread: action 1 queue: save on shutdown 1, max disk space allowed 0
8992.227511084:main thread: action 1 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, qsize 0, child 0 starting
8992.227534830:main thread: Action 0x8cc6ad8: queue 0x8cc6b68 created
8992.227553269:main thread: cfline: 'authpriv.* /var/log/secure'
8992.227576456:main thread: selector line successfully processed
8992.227593497:main thread: - traditional PRI filter
8992.227609980:main thread: symbolic name: * ==> 255
8992.227631770:main thread: symbolic name: authpriv ==> 80
8992.227665574:main thread: tried selector action for builtin-file: 0
8992.227686247:main thread: Module builtin-file processed this config line.
8992.227707478:main thread: template: 'RSYSLOG_FileFormat' assigned
8992.227736812:main thread: action 2 queue: save on shutdown 1, max disk space allowed 0
8992.227759999:main thread: action 2 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, qsize 0, child 0 starting
8992.227781790:main thread: Action 0x8cc6f10: queue 0x8cc6fc0 created
8992.227799669:main thread: cfline: 'mail.* -/var/log/maillog'
8992.227816710:main thread: selector line successfully processed
8992.227832914:main thread: - traditional PRI filter
8992.227849396:main thread: symbolic name: * ==> 255
8992.227870907:main thread: symbolic name: mail ==> 16
8992.227904152:main thread: tried selector action for builtin-file: 0
8992.227920914:main thread: Module builtin-file processed this config line.
8992.227944939:main thread: template: 'RSYSLOG_FileFormat' assigned
8992.227965054:main thread: action 3 queue: save on shutdown 1, max disk space allowed 0
8992.227987123:main thread: action 3 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, qsize 0, child 0 starting
8992.228008914:main thread: Action 0x8cc7388: queue 0x8cc7438 created
8992.228026793:main thread: cfline: 'cron.* -/var/log/cron'
8992.228043555:main thread: selector line successfully processed
8992.228059758:main thread: - traditional PRI filter
8992.228076241:main thread: symbolic name: * ==> 255
8992.228097752:main thread: symbolic name: cron ==> 72
8992.228132952:main thread: tried selector action for builtin-file: 0
8992.228150273:main thread: Module builtin-file processed this config line.
8992.228169270:main thread: template: 'RSYSLOG_FileFormat' assigned
8992.228187429:main thread: action 4 queue: save on shutdown 1, max disk space allowed 0
8992.228215086:main thread: action 4 queue: type 3, enq-only 0, disk assisted 0, maxFileSz 1048576, qsize 0, child 0 starting
8992.228236876:main thread: Action 0x8cc7800: queue 0x8cc78b0 created
8992.228254756:main thread: cfline: '*.emerg *'
8992.228271518:main thread: selector line successfully processed
8992.228288000:main thread: - traditional PRI filter
8992.228304483:main thread: symbolic name: emerg ==> 0
8992.228326832:main thread: tried selector action for builtin-file: -2001
8992.228343873:main thread: tried selector action for builtin-fwd: -2001
8992.228361194:main thread: tried selector action for builtin-shell: -2001
8992.228377956:main thread: tried selector action for builtin-discard: -2001
8992.228394997:main thread: write-alltried selector action for builtin-usrmsg: 0
--

Danke!

Martin

I need the first 100 lines before the TCP error message occurs Because they tell me how many connections are there and why the engine claims no more connections can be accepted

hmm... how do I reproduce that? I can't stop 100+ clients...

Martin

mhhh, I see your problem, but it's hard to diagnose for me with reasonable effort without that. You can simply give it a blind try by adding

$InputTCPMaxSessions 500 (for example)

before $InputTCPServerRun. Maybe that cures the issue. The problem is that my tests with 1,000 connections run flawlessly...

If that doesn't work out, I either need a debug log or give up (as an alternative, you could then think about professional services, so that I could have someone work with you, but that takes a lot of time, which I currently simply do not have).

Rainer

I've set $InputTCPMaxSessions 1000 ... I'll keep an eye open on this for a couple of days and keep you posted...

thanks,
Martin

hmm... stupid question: is there any (theoretical) boundary to $InputTCPMaxSessions ?