> -----Original Message----- > From: [email protected] [mailto:rsyslog- > [email protected]] On Behalf Of George Bonser > Sent: Monday, April 26, 2010 10:52 AM > To: rsyslog-users > Subject: Re: [rsyslog] Problem with 4.6.2 TCP binds after UID non-root. > > I think the problem is that it spawns a new thread to load the udp and > tcp modules and that should be done by the main thread so that it gets > done in sequence before the privs are processed.
I think your analysis is right, this is where the race happens. However, the cure is far from being as simple as it sounds: you are actually recommending a full redesign of the input plugin interface. It would also have other implications, including a potential unacceptable startup delay. This is what I quoted with "a lot of work to do". So, unfortunately, it does not look like something I can fix quickly. Let me once again reiterate that the priv drop code is far from being a complete solution. I added the current code when I saw that it was easy to do and useful for some situations. We once had someone who was interested in sponsoring a complete implementation, but that did unfortunately not materialize. As I am currently short on time due to other work to do, I do not find sufficient time to look at this. It is far from being a trivial task, even though I hope to be able to do it without a full redesign. I still think it is 2+ weeks worth of work. Rainer > > > > > -----Original Message----- > > From: [email protected] [mailto:rsyslog- > > [email protected]] On Behalf Of Rainer Gerhards > > Sent: Monday, April 26, 2010 1:37 AM > > To: rsyslog-users > > Subject: Re: [rsyslog] Problem with 4.6.2 TCP binds after UID > non-root. > > > > No problem -- the mailing list processor held it due to size > > constrainst (and > > I rejected it now). The size restriction was actually the prime issue > > why I > > requested it to go to my private mail. So: nothing bad has happened > ;) > > > > I'll try to look at the log asap and let you know what I find. > > > > Rainer > > > > > -----Original Message----- > > > From: [email protected] [mailto:rsyslog- > > > [email protected]] On Behalf Of George Bonser > > > Sent: Monday, April 26, 2010 10:10 AM > > > To: rsyslog-users > > > Subject: Re: [rsyslog] Problem with 4.6.2 TCP binds after UID non- > > root. > > > > > > Oops, sorry, I did not mean to send that attachment to the list. > > > > > > > -----Original Message----- > > > > From: [email protected] [mailto:rsyslog- > > > > [email protected]] On Behalf Of Rainer Gerhards > > > > Sent: Sunday, April 25, 2010 11:18 PM > > > > To: rsyslog-users > > > > Subject: Re: [rsyslog] Problem with 4.6.2 TCP binds after UID > > > non-root. > > > > > > > > The privilege drop code is still a hack. It needs proper > > engineering > > > > (as > > > > stated in the doc). So it could very well be a race in this > regard. > > > On > > > > the > > > > other hand, it does not look so. Could you send me complete debug > > > logs > > > > to my > > > > private email address both with and without privilege drop inside > > > your > > > > config. Maybe it is a simple thing, then I could fix it without > the > > > > large > > > > effort really required. > > > > > > > > Rainer > > > > > > > > > -----Original Message----- > > > > > From: [email protected] [mailto:rsyslog- > > > > > [email protected]] On Behalf Of George Bonser > > > > > Sent: Monday, April 26, 2010 2:24 AM > > > > > To: rsyslog-users > > > > > Subject: [rsyslog] Problem with 4.6.2 TCP binds after UID non- > > root. > > > > > > > > > > Can't bind to TCP socket. The tcp module loads but I noticed > > that > > > it > > > > > only tries to bind the socket AFTER it has dropped is privs so > it > > > can > > > > > not bind to a socket less than 1024. UDP bind works as that > > seems > > > to > > > > > bind immediately after module load while the prog is still > > running > > > as > > > > > root. If I set a tcp port >1024, it works. Could this be a > race > > > > > between > > > > > two threads where a different thread is setting the UID/GID and > a > > > > > different one is binding the connections and the UID gets > changed > > > > > before > > > > > the binding thread has a chance to get the socket? > > > > > > > > > > Modules being loaded: > > > > > > > > > > 9572.648625421:7f07c0a216f0: cfline: '$ModLoad imudp' > > > > > 9572.648636228:7f07c0a216f0: Requested to load module 'imudp' > > > > > 9572.648645873:7f07c0a216f0: loading module > > > > '/usr/lib/rsyslog/imudp.so' > > > > > 9572.648713628:7f07c0a216f0: source file imudp.c requested > > > reference > > > > > for > > > > > module 'lmnet', reference count now 4 > > > > > 9572.648734955:7f07c0a216f0: module of type 0 being loaded. > > > > > 9572.648747037:7f07c0a216f0: cfline: '$UDPServerRun 514' > > > > > 9572.648759295:7f07c0a216f0: Trying to open syslog UDP ports at > > > > *:514. > > > > > 9572.648845036:7f07c0a216f0: cfline: '$ModLoad imtcp' > > > > > 9572.648859626:7f07c0a216f0: Requested to load module 'imtcp' > > > > > 9572.648869611:7f07c0a216f0: loading module > > > > '/usr/lib/rsyslog/imtcp.so' > > > > > 9572.648938665:7f07c0a216f0: source file imtcp.c requested > > > reference > > > > > for > > > > > module 'lmnet', reference count now 5 > > > > > 9572.648953892:7f07c0a216f0: caller requested object 'netstrm', > > not > > > > > found (iRet -3003) > > > > > 9572.648968610:7f07c0a216f0: Requested to load module > > 'lmnetstrms' > > > > > 9572.648979310:7f07c0a216f0: loading module > > > > > '/usr/lib/rsyslog/lmnetstrms.so' > > > > > 9572.649053366:7f07c0a216f0: module of type 2 being loaded. > > > > > 9572.649068131:7f07c0a216f0: source file imtcp.c requested > > > reference > > > > > for > > > > > module 'lmnetstrms', reference count now 1 > > > > > 9572.649079163:7f07c0a216f0: caller requested object > 'tcps_sess', > > > not > > > > > found (iRet -3003) > > > > > 9572.649095086:7f07c0a216f0: Requested to load module > 'lmtcpsrv' > > > > > 9572.649105485:7f07c0a216f0: loading module > > > > > '/usr/lib/rsyslog/lmtcpsrv.so' > > > > > 9572.649188177:7f07c0a216f0: source file tcps_sess.c requested > > > > > reference > > > > > for module 'lmnetstrms', reference count now 2 > > > > > 9572.649206712:7f07c0a216f0: source file tcpsrv.c requested > > > reference > > > > > for module 'lmnet', reference count now 6 > > > > > 9572.649217297:7f07c0a216f0: source file tcpsrv.c requested > > > reference > > > > > for module 'lmnetstrms', reference count now 3 > > > > > 9572.649231362:7f07c0a216f0: module of type 2 being loaded. > > > > > 9572.649241801:7f07c0a216f0: source file imtcp.c requested > > > reference > > > > > for > > > > > module 'lmtcpsrv', reference count now 1 > > > > > 9572.649252009:7f07c0a216f0: source file imtcp.c requested > > > reference > > > > > for > > > > > module 'lmtcpsrv', reference count now 2 > > > > > 9572.649287366:7f07c0a216f0: module of type 0 being loaded. > > > > > 9572.649299663:7f07c0a216f0: cfline: '$InputTCPServerRun 514' > > > > > 9572.649321373:7f07c0a216f0: cfline: > '$ActionFileDefaultTemplate > > > > > RSYSLOG_TraditionalFileFormat' > > > > > 9572.649334345:7f07c0a216f0: cfline: '$RepeatedMsgReduction on' > > > > > 9572.649382777:7f07c0a216f0: cfline: '$FileOwner syslog' > > > > > 9572.649703828:7f07c0a216f0: uid 101 obtained for user 'syslog' > > > > > 9572.649720763:7f07c0a216f0: cfline: '$FileGroup adm' > > > > > 9572.649790575:7f07c0a216f0: gid 4 obtained for group 'adm' > > > > > 9572.649805222:7f07c0a216f0: cfline: '$FileCreateMode 0640' > > > > > 9572.649816505:7f07c0a216f0: cfline: '$DirCreateMode 0755' > > > > > 9572.649827020:7f07c0a216f0: cfline: '$Umask 0022' > > > > > 9572.649840237:7f07c0a216f0: umask set to 0022. > > > > > 9572.649850064:7f07c0a216f0: cfline: '$PrivDropToUser syslog' > > > > > 9572.649885709:7f07c0a216f0: uid 101 obtained for user 'syslog' > > > > > 9572.649898391:7f07c0a216f0: cfline: '$PrivDropToGroup syslog' > > > > > 9572.649934688:7f07c0a216f0: gid 103 obtained for group > 'syslog' > > > > > 9572.649948278:7f07c0a216f0: cfline: '$IncludeConfig > > > > > /etc/rsyslog.d/*.conf' > > > > > 9572.650017305:7f07c0a216f0: requested to include config file > > > > > '/etc/rsyslog.d/50-default.conf' > > > > > 9572.650045382:7f07c0a216f0: cfline: 'auth,authpriv.* > > > > > /var/log/auth.log' > > > > > > > > > > GID and UID being changed: > > > > > > > > > > 9572.671888467:7f07be402910: doWrite, pData->pStrm 0x1e11d60, > > > lenBuf > > > > 78 > > > > > 9572.671902407:7f07c0a216f0: logmsg: flags 1, from 'trebuchet', > > msg > > > > > rsyslogd's groupid changed to 103 > > > > > 9572.671920644:7f07c0a216f0: Message has legacy syslog format. > > > > > 9572.671933956:7f07be402910: testing filter, f_pmask 1 > > > > > 9572.671947526:7f07be402910: testing filter, f_pmask 240 > > > > > 9572.671957623:7f07be402910: Called action, logging to builtin- > > pipe > > > > > 9572.671969801:7f07be402910: extend buf to at least 16, done > 128 > > > > > 9572.671982061:7f07be402910: (/dev/xconsole) > > > > > 9572.671999956:7f07c0a216f0: main Q: entry added, size now 2 > > > entries > > > > > 9572.672025520:7f07c0a216f0: wtpAdviseMaxWorkers signals busy > > > > > 9572.672041633:7f07c0a216f0: main Q: EnqueueMsg advised worker > > > start > > > > > 9572.672059720:7f07be402910: Action requested to be suspended, > > done > > > > > that. > > > > > 9572.672085037:7f07be402910: main Q: entry deleted, state 0, > size > > > now > > > > 1 > > > > > entries > > > > > 9572.672099142:7f07c0a216f0: setuid(101): 0 > > > > > 9572.672122289:7f07be402910: testing filter, f_pmask 0 > > > > > 9572.672136161:7f07be402910: testing filter, f_pmask 255 > > > > > 9572.672147659:7f07be402910: Called action, logging to builtin- > > file > > > > > 9572.672162158:7f07c0a216f0: logmsg: flags 1, from 'trebuchet', > > msg > > > > > rsyslogd's userid changed to 101 > > > > > 9572.672179992:7f07c0a216f0: Message has legacy syslog format. > > > > > 9572.672192329:7f07be402910: extend buf to at least 138, done > 256 > > > > > 9572.672200766:7f07be402910: file to log to: /var/log/syslog > > > > > > > > > > UDP socket bind succeeded but TCP bind fails: > > > > > > > > > > 9572.672546363:7f07c0a216f0: initialization completed, > > > transitioning > > > > to > > > > > regular run mode > > > > > 9572.672557359:7f07bc3fe910: Listening on UDP syslogd socket 4 > > > > > (IPv4/port 514). > > > > > 9572.672576606:7f07bc3fe910: --------imUDP calling select, > active > > > > file > > > > > descriptors (max 4): 4 > > > > > 9572.672594858:7f07bdc01910: --------imuxsock calling select, > > > active > > > > > file descriptors (max 5): 3 5 > > > > > 9572.672630154:7f07bd400910: wtpAdviseMaxWorkers signals busy > > > > > 9572.672646478:7f07bbbfd910: caller requested object > 'nsd_ptcp', > > > not > > > > > found (iRet -3003) > > > > > 9572.672663716:7f07bbbfd910: Requested to load module > > 'lmnsd_ptcp' > > > > > 9572.672671184:7f07bbbfd910: loading module > > > > > '/usr/lib/rsyslog/lmnsd_ptcp.so' > > > > > 9572.672745761:7f07bbbfd910: source file nsd_ptcp.c requested > > > > reference > > > > > for module 'lmnetstrms', reference count now 4 > > > > > 9572.672757197:7f07bbbfd910: module of type 2 being loaded. > > > > > 9572.672763826:7f07bbbfd910: source file netstrms.c requested > > > > reference > > > > > for module 'lmnsd_ptcp', reference count now 1 > > > > > 9572.672770522:7f07bbbfd910: creating tcp listen socket on port > > 514 > > > > > 9572.672803781:7f07bbbfd910: error 13 while binding tcp > socketWe > > > > could > > > > > initialize 0 TCP listen sockets out of 1 we recei > > > > > ved - this may or may not be an error indication. > > > > > 9572.672824933:7f07bbbfd910: No TCP listen sockets could > > > successfully > > > > > be > > > > > initializedCalled LogError, msg: Could not crea > > > > > te tcp listener, ignoring port 514. > > > > > 9572.672844597:7f07bbbfd910: logmsg: flags 1, from 'trebuchet', > > msg > > > > > Could not create tcp listener, ignoring port 514. [t > > > > > ry http://www.rsyslog.com/e/2077 ] > > > > > > > > > > _______________________________________________ > > > > > rsyslog mailing list > > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > > http://www.rsyslog.com > > > > _______________________________________________ > > > > rsyslog mailing list > > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > > http://www.rsyslog.com > > > _______________________________________________ > > > rsyslog mailing list > > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > > http://www.rsyslog.com > > _______________________________________________ > > rsyslog mailing list > > http://lists.adiscon.net/mailman/listinfo/rsyslog > > http://www.rsyslog.com > _______________________________________________ > rsyslog mailing list > http://lists.adiscon.net/mailman/listinfo/rsyslog > http://www.rsyslog.com _______________________________________________ rsyslog mailing list http://lists.adiscon.net/mailman/listinfo/rsyslog http://www.rsyslog.com
