This problem reminds me of this issue (which was corrected): https://github.com/rsyslog/rsyslog/issues/2787#issuecomment-403227370
And could also be related to this problem (the reporter didn't follow up): https://github.com/rsyslog/rsyslog/issues/3361#issuecomment-481631043 One point to consider is that when starting rsyslog as a daemon (i.e. when the -n option is NOT given), stdin, stdout and stderr are not assigned, and hence other specific file descriptors (specifically, the ones used for the pipes with omprog) could potentially reuse these fd numbers. After a quick glance in how omprog handles the pipe fds, I haven't seen a possible bug related to this, but obviously we can't rule this out... I will try to reproduce the problem using the testbench (not sure when though, don't count on a quick response...). AFAIK the testbench always launches rsyslog in non-daemon mode. Rainer, is there an easy way to run the testbench in daemon mode? Derek, a couple of questions for you: - Does it happen with forceSingleInstance="off"? (this would definitely point to a possible bug in omprog) - Can you reproduce it consistently? (when starting rsyslog in daemon mode) Or sometimes works? Also I would recommend opening a github issue. (Even if it's not a bug in rsyslog/omprog, the resolution could be useful to other users having the same problem.) Attaching a debug log could also be useful. Regarding this: > I have tried adding 'output' to the action configuration, thinking I would > get messages, but haven't gotten anything. > That's expected: omprog is not able to communicate to the program (the pipe fd's are broken/unusable), so its output can't be captured either. Regards Joan On Tue, Apr 14, 2020 at 4:46 PM Derek Dresser via rsyslog < [email protected]> wrote: > Rainer, > Thank you for the response. I agree that it sounds like a system problem, > not necessarily syslogd or omprog. This is an embedded system and doesn't > have any selinux. I have disabled all cgroup functionality as well. Debug > logging, etc. hasn't provided any clues. Given that it is the root user > starting rsyslog in both cases, what is different when rsyslogd is started > with the -n flag? Also with your deep understanding of omprog, do you have > any tips that might help me get more insight into what is happening? > Thank you, > Derek > > On Tue, Apr 14, 2020 at 5:34 AM Rainer Gerhards <[email protected]> > wrote: > > > This sounds like a problem with SELinux or a similar hardening system. > > > > HTH > > Rainer > > > > El lun., 13 abr. 2020 a las 4:20, Derek Dresser via rsyslog > > (<[email protected]>) escribió: > > > > > > Hello, > > > > > > I am troubleshooting an issue on a Yocto based distribution with > sending > > > logs > > > to a python program '/usr/bin/logoutput' via omprog. If rsyslogd is > > started > > > by init script, or by me (as root) on the command line, I get the > > following > > > errors. > > > > > > apr 12 21:35:02.865327 RSYSLO action 'action-1-omprog' resumed (module > > > 'omprog') [v8.2002.0 try https://www.rsyslog.com/e/2359 ] > > > apr 12 21:35:02.865350 RSYSLO omprog: error sending message to > program: > > Bad > > > file descriptor [v8.2002.0 try https://www.rsyslog.com/e/2119 ] > > > apr 12 21:35:02.865365 RSYSLO action 'action-1-omprog' suspended > (module > > > 'omprog'), retry 0. There should be messages before this one giving the > > > reason f > > > or suspension. [v8.2002.0 try https://www.rsyslog.com/e/2007 ] > > > apr 12 21:35:03.866356 RSYSLO action 'action-1-omprog' suspended > (module > > > 'omprog'), next retry is Sun Apr 12 21:35:33 2020, retry nbr 0. There > > should > > > be > > > messages before this one giving the reason for suspension. [v8.2002.0 > try > > > https://www.rsyslog.com/e/2007 ] > > > > > > > > > and I never see 'logoutput' in the process listing. However, if I > start > > > rsyslogd with '-n' (foreground), my program is started and messages are > > > delivered as expected. Even if I start it with -n and send it to the > > > background it is fine (rsyslogd -n &) I don't have selinux or anything > > > enabled. > > > > > > I have tried adding 'output' to the action configuration, thinking I > > would > > > get messages, but haven't gotten anything. > > > > > > action(type="omprog" > > > binary="/usr/bin/logoutput" > > > forceSingleInstance="on" > > > output="/tmp/omprog.out" > > > template="output") > > > > > > here are the lsof listings rsyslogd being started by init script > > > > > > root@zcu102-zynqmp:/tmp/bin# lsof -p 6204 > > > COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE > > NAME > > > rsyslogd 6204 root cwd DIR 179,2 4096 2 / > > > rsyslogd 6204 root rtd DIR 179,2 4096 2 / > > > rsyslogd 6204 root txt REG 179,2 678072 19325 > > > /usr/sbin/rsyslogd > > > rsyslogd 6204 root mem REG 179,2 27208 19316 > > > /usr/lib/rsyslog/omprog.so > > > rsyslogd 6204 root mem REG 179,2 14528 19312 > > > /usr/lib/rsyslog/mmjsonparse.so > > > rsyslogd 6204 root mem REG 179,2 19680 19292 > > > /usr/lib/rsyslog/imklog.so > > > rsyslogd 6204 root mem REG 179,2 32912 19298 > > > /usr/lib/rsyslog/imuxsock.so > > > rsyslogd 6204 root mem REG 179,2 46984 907 > > /lib/ > > > libnss_files-2.30.so > > > rsyslogd 6204 root mem REG 179,2 23416 19300 > > > /usr/lib/rsyslog/lmnet.so > > > rsyslogd 6204 root mem REG 179,2 1400792 874 > > /lib/ > > > libc-2.30.so > > > rsyslogd 6204 root mem REG 179,2 27000 935 > > > /lib/libuuid.so.1.3.0 > > > rsyslogd 6204 root mem REG 179,2 43496 10991 > > > /usr/lib/libfastjson.so.4.2.0 > > > rsyslogd 6204 root mem REG 179,2 14168 10983 > > > /usr/lib/libestr.so.0.0.0 > > > rsyslogd 6204 root mem REG 179,2 14208 884 > > /lib/ > > > libdl-2.30.so > > > rsyslogd 6204 root mem REG 179,2 113104 915 > > /lib/ > > > libpthread-2.30.so > > > rsyslogd 6204 root mem REG 179,2 88304 939 > > > /lib/libz.so.1.2.11 > > > rsyslogd 6204 root mem REG 179,2 136752 862 > > /lib/ > > > ld-2.30.so > > > rsyslogd 6204 root 0r CHR 1,9 0t0 1032 > > > /dev/urandom > > > rsyslogd 6204 root 1u unix 0xffffffc05fdda000 0t0 40009 > > > type=DGRAM > > > rsyslogd 6204 root 2w REG 179,4 10350 131078 > > > /data/log/syslog.log > > > rsyslogd 6204 root 3u unix 0xffffffc05fdda480 0t0 40006 > > > /dev/log type=DGRAM > > > rsyslogd 6204 root 4r REG 0,4 0 4026531950 > > > /proc/kmsg > > > > > > and when started in the foreground (rsyslogd -n &) > > > > > > root@zcu102-zynqmp:/tmp/bin# lsof -p 6239 > > > COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE > > NAME > > > rsyslogd 6239 root cwd DIR 179,2 4096 2 / > > > rsyslogd 6239 root rtd DIR 179,2 4096 2 / > > > rsyslogd 6239 root txt REG 179,2 678072 19325 > > > /usr/sbin/rsyslogd > > > rsyslogd 6239 root mem REG 179,2 27208 19316 > > > /usr/lib/rsyslog/omprog.so > > > rsyslogd 6239 root mem REG 179,2 14528 19312 > > > /usr/lib/rsyslog/mmjsonparse.so > > > rsyslogd 6239 root mem REG 179,2 19680 19292 > > > /usr/lib/rsyslog/imklog.so > > > rsyslogd 6239 root mem REG 179,2 32912 19298 > > > /usr/lib/rsyslog/imuxsock.so > > > rsyslogd 6239 root mem REG 179,2 46984 907 > > /lib/ > > > libnss_files-2.30.so > > > rsyslogd 6239 root mem REG 179,2 23416 19300 > > > /usr/lib/rsyslog/lmnet.so > > > rsyslogd 6239 root mem REG 179,2 1400792 874 > > /lib/ > > > libc-2.30.so > > > rsyslogd 6239 root mem REG 179,2 27000 935 > > > /lib/libuuid.so.1.3.0 > > > rsyslogd 6239 root mem REG 179,2 43496 10991 > > > /usr/lib/libfastjson.so.4.2.0 > > > rsyslogd 6239 root mem REG 179,2 14168 10983 > > > /usr/lib/libestr.so.0.0.0 > > > rsyslogd 6239 root mem REG 179,2 14208 884 > > /lib/ > > > libdl-2.30.so > > > rsyslogd 6239 root mem REG 179,2 113104 915 > > /lib/ > > > libpthread-2.30.so > > > rsyslogd 6239 root mem REG 179,2 88304 939 > > > /lib/libz.so.1.2.11 > > > rsyslogd 6239 root mem REG 179,2 136752 862 > > /lib/ > > > ld-2.30.so > > > rsyslogd 6239 root 0u CHR 253,0 0t0 1522 > > > /dev/ttyPS0 > > > rsyslogd 6239 root 1u CHR 253,0 0t0 1522 > > > /dev/ttyPS0 > > > rsyslogd 6239 root 2u CHR 253,0 0t0 1522 > > > /dev/ttyPS0 > > > rsyslogd 6239 root 3r CHR 1,9 0t0 1032 > > > /dev/urandom > > > rsyslogd 6239 root 4r FIFO 0,9 0t0 39109 > > pipe > > > rsyslogd 6239 root 5w FIFO 0,9 0t0 39109 > > pipe > > > rsyslogd 6239 root 6u unix 0xffffffc05c6524c0 0t0 39111 > > > /dev/log type=DGRAM > > > rsyslogd 6239 root 7w FIFO 0,9 0t0 39110 > > pipe > > > rsyslogd 6239 root 8r REG 0,4 0 4026531950 > > > /proc/kmsg > > > rsyslogd 6239 root 9u unix 0xffffffc05c652040 0t0 39114 > > > type=DGRAM > > > rsyslogd 6239 root 10w REG 179,4 10484 131078 > > > /data/log/syslog.log > > > > > > and here are pstree listings for each case. first when started by init > > > script > > > > > > root@zcu102-zynqmp:/tmp/bin# pstree -ps 6318 > > > init(1)---rsyslogd(6318)-+-{rsyslogd}(6319) > > > |-{rsyslogd}(6320) > > > `-{rsyslogd}(6322) > > > > > > and when started with rsyslogd -n & > > > root@zcu102-zynqmp:/tmp/bin# pstree -ps 6351 > > > > > > init(1)---start_getty(3688)---login(3715)---sh(3752)---rsyslogd(6351)-+-logoutput(6353)---{logoutput}(6357) > > > > > > |-{rsyslogd}(6352) > > > > > > |-{rsyslogd}(6354) > > > > > > |-{rsyslogd}(6355) > > > > > > `-{rsyslogd}(6356) > > > > > > you can see that when I start it with the '-n' flag, my program gets > > started > > > and rsyslogd has a pipe to it. Can someone help me understand why this > > is > > > only working for me when I use the '-n' flag. In both cases, it is > > started > > > as root, so it doesn't seem like a permissions issue. > > > > > > Thanks > > > _______________________________________________ > > > 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. _______________________________________________ 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.
