* s6 problems logging @ 2019-01-27 3:15 Sean MacLennan 2019-01-27 5:20 ` Colin Booth 2019-01-27 14:39 ` smaclennan/doorknob Jonathan de Boyne Pollard 0 siblings, 2 replies; 12+ messages in thread From: Sean MacLennan @ 2019-01-27 3:15 UTC (permalink / raw) To: supervision I have a service called doorknob that I want to log the output of. Here is the run file: #!/command/execlineb -P /usr/sbin/doorknob -fs The -f keeps doorknob in the foreground and the -s sends all messages to stdout. The log/run file is: #!/command/execlineb -P s6-log -b n20 s1000000 t . My understanding is that the stdout should go to s6-log and be put in log/current. But nothing seems to be logged. Cheers, Sean https://github.com/smaclennan/doorknob ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: s6 problems logging 2019-01-27 3:15 s6 problems logging Sean MacLennan @ 2019-01-27 5:20 ` Colin Booth 2019-01-27 16:47 ` Sean MacLennan 2019-01-27 14:39 ` smaclennan/doorknob Jonathan de Boyne Pollard 1 sibling, 1 reply; 12+ messages in thread From: Colin Booth @ 2019-01-27 5:20 UTC (permalink / raw) To: supervision On Sat, Jan 26, 2019 at 10:15:17PM -0500, Sean MacLennan wrote: > I have a service called doorknob that I want to log the output of. Here > is the run file: > > #!/command/execlineb -P > /usr/sbin/doorknob -fs > > The -f keeps doorknob in the foreground and the -s sends all messages > to stdout. > > The log/run file is: > > #!/command/execlineb -P > s6-log -b n20 s1000000 t . > > My understanding is that the stdout should go to s6-log and be put in > log/current. But nothing seems to be logged. > > Cheers, > Sean > > https://github.com/smaclennan/doorknob Everything looks fine from over here. Does running doorknob with -fs from the terminal do what you expect? Also, what does `s6-svstat PATH_TO_DOORKNOB_SVCDIR' and `s6-svstat PATH_TO_DOORKNOB_SVCDIR/log' tell you? Also, does the target dir for s6-log have the files "current" (apparently not), "lock", and "state"? Those final two files are created by s6-log automatically and should at least indicate that it's starting up fine. Cheers! -Colin -- Colin Booth ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: s6 problems logging 2019-01-27 5:20 ` Colin Booth @ 2019-01-27 16:47 ` Sean MacLennan 2019-01-27 17:56 ` Laurent Bercot ` (2 more replies) 0 siblings, 3 replies; 12+ messages in thread From: Sean MacLennan @ 2019-01-27 16:47 UTC (permalink / raw) To: Colin Booth; +Cc: supervision On Sun, 27 Jan 2019 05:20:00 +0000 Colin Booth <colin@heliocat.net> wrote: > Everything looks fine from over here. Does running doorknob with -fs > from the terminal do what you expect? Yup, I get a log message to the console when I send an email. > Also, what does > `s6-svstat PATH_TO_DOORKNOB_SVCDIR' and > `s6-svstat PATH_TO_DOORKNOB_SVCDIR/log' > tell you? /service/doorknob# /command/s6-svstat . up (pid 948) 47861 seconds /service/doorknob# /command/s6-svstat log up (pid 847) 75815 seconds Log has been up longer because I restarted doorknob with an s6-svc down/up. Not sure if this is kosher with logging. Is there a recommended way to start/stop services that have logging? > Also, does the target dir for s6-log have the files > "current" (apparently not), "lock", and "state"? Those final two > files are created by s6-log automatically and should at least > indicate that it's starting up fine. /service/doorknob# ls log current event lock run state supervise So it does have all the files/directories but current is empty even though there should be some log entries. I do use s6-log in one other service and it works. In the service/s6-svscan-log I have: #!/command/execlineb -P cat ./fifo And the same log/run as doorknob. Cheers, Sean ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: s6 problems logging 2019-01-27 16:47 ` Sean MacLennan @ 2019-01-27 17:56 ` Laurent Bercot 2019-01-27 18:13 ` Colin Booth 2019-01-27 18:56 ` Sean MacLennan 2 siblings, 0 replies; 12+ messages in thread From: Laurent Bercot @ 2019-01-27 17:56 UTC (permalink / raw) To: supervision >Yup, I get a log message to the console when I send an email. Try stracing doorknob: "strace -v -s 256 /usr/sbin/doorknob -fs" in your run script. Check that the messages it's sending to its stdout are properly terminated with a newline or null character. (Messages sent to the console will appear even if they're not terminated with a newline; but s6-log will keep them in the buffer until it gets a terminator.) Even if it's not the problem, strace may give you a hint of what is happening. If it doesn't, pastebin it somewhere and give us the link. -- Laurent ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: s6 problems logging 2019-01-27 16:47 ` Sean MacLennan 2019-01-27 17:56 ` Laurent Bercot @ 2019-01-27 18:13 ` Colin Booth 2019-01-27 18:56 ` Sean MacLennan 2 siblings, 0 replies; 12+ messages in thread From: Colin Booth @ 2019-01-27 18:13 UTC (permalink / raw) To: supervision On Sun, Jan 27, 2019 at 11:47:51AM -0500, Sean MacLennan wrote: > On Sun, 27 Jan 2019 05:20:00 +0000 > Colin Booth <colin@heliocat.net> wrote: > > > Everything looks fine from over here. Does running doorknob with -fs > > from the terminal do what you expect? > > Yup, I get a log message to the console when I send an email. > > > Also, what does > > `s6-svstat PATH_TO_DOORKNOB_SVCDIR' and > > `s6-svstat PATH_TO_DOORKNOB_SVCDIR/log' > > tell you? > > /service/doorknob# /command/s6-svstat . > up (pid 948) 47861 seconds > /service/doorknob# /command/s6-svstat log > up (pid 847) 75815 seconds > > Log has been up longer because I restarted doorknob with an s6-svc > down/up. Not sure if this is kosher with logging. Is there a > recommended way to start/stop services that have logging? > That should be fine. The only requirement that I know of is that you re-register the service directory if you add or remove a log/ dir since the presence or absence of a log/ directory is only checked when s6-svscan first checks the directory. Reregistration in this case means: delete the symlink, run s6-svscanctl -an, confirm that the removed service has exited, create the symlink, and re-run s6-svscanctl -an. Downing a logger may or may not cause problems, depending on how many messages your service sends. Not because you'll lose stuff, but because the service will block eventually as it tries to write to a pipe that isn't being drained. > > Also, does the target dir for s6-log have the files > > "current" (apparently not), "lock", and "state"? Those final two > > files are created by s6-log automatically and should at least > > indicate that it's starting up fine. > > /service/doorknob# ls log > current event lock run state supervise > > So it does have all the files/directories but current is empty even > though there should be some log entries. > Cool, that means everything can write correctly. > > I do use s6-log in one other service and it works. In the > service/s6-svscan-log I have: > > #!/command/execlineb -P > cat ./fifo > > And the same log/run as doorknob. > > Cheers, > Sean As Laurent mentioned, it sounds like your service isn't terminating its lines correctly. The other option is that you're writing your messages to stderr instead of stdout (in which case you'd end up on the catch-all logger unless you did `fdmove -c 2 1' in your doorknob script before starting doorknob itself. That said, it's unlikely, since vprintf seems to wite to stdout unless you tell it otherwise. -- Colin Booth ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: s6 problems logging 2019-01-27 16:47 ` Sean MacLennan 2019-01-27 17:56 ` Laurent Bercot 2019-01-27 18:13 ` Colin Booth @ 2019-01-27 18:56 ` Sean MacLennan 2019-01-27 19:27 ` Roger Pate 2019-01-27 19:35 ` Guillermo 2 siblings, 2 replies; 12+ messages in thread From: Sean MacLennan @ 2019-01-27 18:56 UTC (permalink / raw) To: supervision So it seems that s6-log does not like buffered output. I modified doorknob to vsnprintf into a buffer and then tried various output methods. 1. puts(msg) Failed as expected (basically the same as vprintf). 2. write(1, msg, strlen(msg)) Worked! So non-buffered ok. 3. fputs(msg, stderr) Then add `fdmove -c 2 1' to the run file works! So fdmove seems to fix things up. Which is probably why most people don't see this problem. Obviously, for 2 and 3 I did a strcat(msg, "\n"). So I think I will go with 2, but to stderr to follow Jonathan de Boyne Pollard's comment "Unix conventions: Logs go to standard error". Thanks everybody for the input. I probably would not have suspected the buffered output was a problem. Cheers, Sean ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: s6 problems logging 2019-01-27 18:56 ` Sean MacLennan @ 2019-01-27 19:27 ` Roger Pate 2019-01-28 11:00 ` Peter Pentchev 2019-01-27 19:35 ` Guillermo 1 sibling, 1 reply; 12+ messages in thread From: Roger Pate @ 2019-01-27 19:27 UTC (permalink / raw) To: Sean MacLennan; +Cc: supervision On Sun, Jan 27, 2019 at 1:56 PM Sean MacLennan <seanm@seanm.ca> wrote: > So it seems that s6-log does not like buffered output. I modified > doorknob to vsnprintf into a buffer and then tried various output > methods. s6-log (or another program) has no idea about your buffered output. Output cannot be read until it has been written, and data still in a buffer has not been written. Change your program to flush after messages. It is common for stdio to buffer stdout differently depending on whether it is a terminal and to not make that distinction for stderr. In your terminal, compare "doorknob -fs" (stdout as terminal) to "doorknob -fs | cat" (stdout as pipe) to see the difference. PS. You have "dump" twice where I think you mean "dumb", in your Github description and in your README. ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: s6 problems logging 2019-01-27 19:27 ` Roger Pate @ 2019-01-28 11:00 ` Peter Pentchev 2019-02-01 9:22 ` Jonathan de Boyne Pollard 0 siblings, 1 reply; 12+ messages in thread From: Peter Pentchev @ 2019-01-28 11:00 UTC (permalink / raw) To: Roger Pate; +Cc: Sean MacLennan, supervision [-- Attachment #1: Type: text/plain, Size: 1228 bytes --] On Sun, Jan 27, 2019 at 02:27:10PM -0500, Roger Pate wrote: > On Sun, Jan 27, 2019 at 1:56 PM Sean MacLennan <seanm@seanm.ca> wrote: > > So it seems that s6-log does not like buffered output. I modified > > doorknob to vsnprintf into a buffer and then tried various output > > methods. > > s6-log (or another program) has no idea about your buffered output. > Output cannot be read until it has been written, and data still in a > buffer has not been written. Change your program to flush after > messages. It is common for stdio to buffer stdout differently > depending on whether it is a terminal and to not make that distinction > for stderr. In your terminal, compare "doorknob -fs" (stdout as > terminal) to "doorknob -fs | cat" (stdout as pipe) to see the > difference. If it is not easy to change the program itself, the stdbuf(1) utility in recent versions of coreutils might help (of course, if you use some kind of minimal system, it may not always be available). G'luck, Peter -- Peter Pentchev roam@{ringlet.net,debian.org,FreeBSD.org} pp@storpool.com PGP key: http://people.FreeBSD.org/~roam/roam.key.asc Key fingerprint 2EE7 A7A5 17FC 124C F115 C354 651E EFB0 2527 DF13 [-- Attachment #2: signature.asc --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: s6 problems logging 2019-01-28 11:00 ` Peter Pentchev @ 2019-02-01 9:22 ` Jonathan de Boyne Pollard 0 siblings, 0 replies; 12+ messages in thread From: Jonathan de Boyne Pollard @ 2019-02-01 9:22 UTC (permalink / raw) To: supervision [-- Attachment #1: Type: text/plain, Size: 593 bytes --] Peter Pentchev: > If it is not easy to change the program itself, the stdbuf(1) utility > [...] > I am certain that M. MacLennan is capable of changing M. MacLennan's own program. After all, you are replying to a message where xe said that xe already did. (-: Injecting things into the code of the running program via pre-loads should be a last resort, not on an equal footing with adjusting the program's logging. In any case, the Bernstein |ptybandage| <http://jdebp.eu./Softwares/djbwares/bernstein-ptyget.html> achieves this /without/ injecting code into the target programs. ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: s6 problems logging 2019-01-27 18:56 ` Sean MacLennan 2019-01-27 19:27 ` Roger Pate @ 2019-01-27 19:35 ` Guillermo 1 sibling, 0 replies; 12+ messages in thread From: Guillermo @ 2019-01-27 19:35 UTC (permalink / raw) To: Supervision Hello, El dom., 27 ene. 2019 a las 15:56, Sean MacLennan escribió: > > So it seems that s6-log does not like buffered output. It probably isn't that it doesn't like it, but that it doesn't even get to see the output. As Jonathan also pointed out, when you run doorknob using a supervision suite, stdout is redirected to a pipe, which is not an 'interactive device' (unlike an interactive shell's controlling terminal) so it is fully buffered. And at least GNU libc's implementation of the <stdio.h> interface buffers indeed. A smaller program that does your vprintf() + putchar('\n') sequence exhibits this behaviour, and adding an fflush(stdout) call solves it. But... > I modified > doorknob to vsnprintf into a buffer and then tried various output > methods. > > 1. puts(msg) Failed as expected (basically the same as vprintf). > > 2. write(1, msg, strlen(msg)) Worked! So non-buffered ok. > > 3. fputs(msg, stderr) Then add `fdmove -c 2 1' to the run file works! > So fdmove seems to fix things up. Which is probably why most people > don't see this problem. > > Obviously, for 2 and 3 I did a strcat(msg, "\n"). > > So I think I will go with 2, but to stderr to follow Jonathan de Boyne > Pollard's comment "Unix conventions: Logs go to standard error". If you want minimal changes and follow the convention of logging to stderr, you could have done vfprintf(stderr, fmt, ap) + fputc('\n', stderr), which also works. stderr is never fully buffered. G. ^ permalink raw reply [flat|nested] 12+ messages in thread
* smaclennan/doorknob 2019-01-27 3:15 s6 problems logging Sean MacLennan 2019-01-27 5:20 ` Colin Booth @ 2019-01-27 14:39 ` Jonathan de Boyne Pollard 2019-02-02 18:32 ` smaclennan/doorknob Sean MacLennan 1 sibling, 1 reply; 12+ messages in thread From: Jonathan de Boyne Pollard @ 2019-01-27 14:39 UTC (permalink / raw) To: supervision [-- Attachment #1: Type: text/plain, Size: 3510 bytes --] * The plural of "address" is "addresses". "-ii" is not how any word pluralizes in English. * The way to monitor such a directory nowadays is with |kevent(EVFILT_VNODE)| or |inotify_*()|. * Long-known multi-user spool security precautions: /Always/ check the |d_type|; /always/ |fstatat()|/|fstat()| the spool file and check for |S_ISREG()|. * Long-known multi-user spool security precautions: Spool areas should be beneath a non-world-accessible parent directory, and the program that dumps into the spool should be set-group-ID to a group (or a /non-owner/ user) that has search access on the parent in order to reach the spool directory beneath. Not doing this is an error that was initially made in Postfix years ago, avoiding all set-ID programs without realizing that set-ID is a necessarymechanism for secure multi-user spooling when it is in this form. (See Bruce Guenter's bcron <http://untroubled.org/bcron/> for an example of an alternative way that multi-user spooling can be structured using a submission server and UCSPI-UNIX.) The spool-processing dæmon itself does not need to run under the aegis of this group, if it is simply started up already in its spool directory using |chdir| <http://jdebp.eu./Softwares/nosh/guide/commands/chdir.xml> (or cd <http://skarnet.org./software/execline/cd.html> or equivalent) in the |run| script. (This also means that it does not need to hardcode the location of its spool directory. Its spool directory is its working directory, where it works.) * Other security precautions: Dæmons such as this should /always/ |setuidgid| <http://jdebp.eu./Softwares/nosh/guide/commands/setuidgid.xml> away from the superuser in their |run| scripts to an account dedicated to the dæmon. (Compare the |run| script in Bruce Guenter's nullmailer <http://untroubled.org/nullmailer/>.) o Jonathan de Boyne Pollard (2019). "Limiting services: Running under the aegises of unprivileged user accounts <http://jdebp.eu./Softwares/nosh/guide/limiting-services.html#users>". /nosh Guide/. Softwares. o https://unix.stackexchange.com/questions/450251/ * Other spool-processing dæmon security measures: The dedicated user account has no need to own /anything/, neither the spooled files nor the spool directory itself. It needs only read+write+execute permission on the spool directory, and read permission on the spool files. Having ownership permission as well permits compromised dæmons to change ACLs and permissions. o Jonathan de Boyne Pollard (2019). "Log service security: Dedicated log user accounts <http://jdebp.eu./Softwares/nosh/guide/log-service-security.html#users>"./nosh Guide/. Softwares. * Debian family operating system conventions: That has not been the way to write a van Smoorenburg |rc| script for Debian family operating systems since 2014. o Petter Reinholdtsen (2014-02-09). init-d-script <https://manpages.debian.org/stretch/sysvinit-utils/init-d-script.5.en.html>. /File formats manual/. Debian. * C language standards: |stdout| is fully buffered if it is not an interactive device, which a pipe is indeed not. |stderr| is of course /not/ fully buffered. * Unix conventions: Logs go to standard error. ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: smaclennan/doorknob 2019-01-27 14:39 ` smaclennan/doorknob Jonathan de Boyne Pollard @ 2019-02-02 18:32 ` Sean MacLennan 0 siblings, 0 replies; 12+ messages in thread From: Sean MacLennan @ 2019-02-02 18:32 UTC (permalink / raw) To: Jonathan de Boyne Pollard; +Cc: supervision On Sun, 27 Jan 2019 14:39:16 +0000 Jonathan de Boyne Pollard <J.deBoynePollard-newsgroups@NTLWorld.COM> wrote: > A lot of constructive comments on doorknob which I am not going to > include here. Well, I have updated doorknob to *hopefully* respond to all the comments. I have pushed the changes to github if anybody is interested. The big changes are moving the default location of the directories and changing ownership. Doorknob now has its own user. It basically does: 1. change to queue directory 2. setup inotify 3. drop privileges to doorknob user 4. read config 5. start handling messages sendmail and mailq are now owned by the mail user and group (configurable) and are +s. The queues are now (by default): chown mail.mail /var/spool/doorknob chown mail.mail /var/spool/doorknob/queue chown mail.mail /var/spool/doorknob/tmp chmod 750 /var/spool/doorknob chmod 777 /var/spool/doorknob/queue chmod 700 /var/spool/doorknob/tmp Everything is configurable. You can make the doorknob user root, the mail user root, and everything is as before. Comments welcome. Cheers, Sean ^ permalink raw reply [flat|nested] 12+ messages in thread
end of thread, other threads:[~2019-02-02 18:32 UTC | newest] Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2019-01-27 3:15 s6 problems logging Sean MacLennan 2019-01-27 5:20 ` Colin Booth 2019-01-27 16:47 ` Sean MacLennan 2019-01-27 17:56 ` Laurent Bercot 2019-01-27 18:13 ` Colin Booth 2019-01-27 18:56 ` Sean MacLennan 2019-01-27 19:27 ` Roger Pate 2019-01-28 11:00 ` Peter Pentchev 2019-02-01 9:22 ` Jonathan de Boyne Pollard 2019-01-27 19:35 ` Guillermo 2019-01-27 14:39 ` smaclennan/doorknob Jonathan de Boyne Pollard 2019-02-02 18:32 ` smaclennan/doorknob Sean MacLennan
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).