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
