A better method than daisy-chaining logging files?

A better method than daisy-chaining logging files?

[Dewayne Geraghty]

I'm still working the Apache problem, and I'm using s6-log to manage the
logs.

I just attempted to link an apache24 instance to its log files via a
bundle, which isn't acceptable to s6-rc-compile.

The approach attempted was to chain:
1. apache24 (longrun) and is a producer-for apache24-log
2. apache24-log (bundle) is a consumer-for apache24, with contents, the
following, two longrun's for logging)
3. apache24-access-log (longrun) & apache24-error-log (longrun)

Is it envisaged that s6-rc would enable something like this in the
future, or will the following method remain:

1. apache24 (longrun) and is a producer-for apache24-access-log
-. apache24-log (bundle) [ only for admin, though largely redundant ]
2. apache24-access-log (longrun) consumer-for apache24, producer-for
apache24-error-log
3. apache24-error-log (longrun) consumer-for apache24-access-log

The link between items 2 and 3 is fictional as is the absence of a
connection between 1 and 3.

Ideally having:
apache24 as producer-for (both) apache24-access-log and
apache24-error-log  might be another option as it reflects reality.  But
this also isn't acceptable to the s6-rc-compile.

This is a very simplified example as I have 6 sites to manage, and its
seems wrong to complicate the setup with artificial links with s6-rc?

I'm very interested to understand the reasoning.

Kind regards, Dewayne

Re: A better method than daisy-chaining logging files?

[Laurent Bercot]

[-- Attachment #1: Type: text/plain, Size: 4018 bytes --]

>I just attempted to link an apache24 instance to its log files via a
>bundle, which isn't acceptable to s6-rc-compile.
>
>The approach attempted was to chain:
>1. apache24 (longrun) and is a producer-for apache24-log
>2. apache24-log (bundle) is a consumer-for apache24, with contents, the
>following, two longrun's for logging)
>3. apache24-access-log (longrun) & apache24-error-log (longrun)

Producers and consumers have to be atomic services. You cannot
declare that a bundle is a consumer.


>Is it envisaged that s6-rc would enable something like this in the
>future, or will the following method remain:
>
>1. apache24 (longrun) and is a producer-for apache24-access-log
>-. apache24-log (bundle) [ only for admin, though largely redundant ]
>2. apache24-access-log (longrun) consumer-for apache24, producer-for
>apache24-error-log
>3. apache24-error-log (longrun) consumer-for apache24-access-log
>
>The link between items 2 and 3 is fictional as is the absence of a
>connection between 1 and 3.

That would work, but declare the following chain of data:
apache24 -> apache24-access-log -> apache24-error-log
which doesn't reflect your real setup. It would essentially
create and maintain an anonymous pipe between apache24-access-log
and apache24-error-log which would not be used - unless you
manually retrieve it from s6rc-fdholder and use it with apache24.
Which would work, but would be a hack that breaks abstractions.


>Ideally having:
>apache24 as producer-for (both) apache24-access-log and
>apache24-error-log  might be another option as it reflects reality.  But
>this also isn't acceptable to the s6-rc-compile.
>
>This is a very simplified example as I have 6 sites to manage, and its
>seems wrong to complicate the setup with artificial links with s6-rc?
>
>I'm very interested to understand the reasoning.

The point of declaring producers and consumers in s6-rc is to
automatically manage pipelines: the stdout of a producer is
automatically redirected to the stdin of the corresponding consumer.
The feature uses Unix pipes, and one of the limitations of pipes is
that you can have several writers to one reader (which is supported
by s6-rc: you can have several producers for a unique consumer), but
you cannot have more than one reader on a pipe. So you cannot
declare several consumers on the same producer, because it would
mean having several processes reading from the consumer's stdout.

The model is limited in that it's only usable for stdin and stdout;
when a service, like apache24, produces several streams of data,
you can only fit one in the model (if you can get it to output one
of those streams to stdout), and the others have to be handled
differently.
Changing this is not planned atm, because it would make the model
significantly more complex (require the producer to list which fds
it's writing to, etc.) for a feature that would only be useful for
a few services - apache httpd unfortunately being one of them.

My advice is to use s6-rc's producer/consumer mechanism for one
of the log streams, and use a named pipe for the other one, without
cramming it into the s6-rc mechanism. That would typically mean:

- configure apache24 to output its access log to stdout
- declare apache24 as a producer for apache24-access-log and
apache24-access-log as a consumer for apache24
- apache24-access-log is a simple s6-log invocation, reading
from its stdin
- mkfifo /var/run/apache24/error-fifo (with appropriate rights)
- declare that apache24 outputs its error log to
/var/run/apache24/error-fifo
- apache24-error-log has its run script doing something like:
redirfd -r 0 /var/run/apache24/error-fifo s6-log your-logging-script
- manually list apache24-error-log in apache24's dependencies, so
apache24 doesn't start before apache24-error-log. (The pipeline
mechanism automatically adds apache24-access-log to apache24's deps.)
- manually define any bundles you want.

HTH,

--
Laurent

Re: A better method than daisy-chaining logging files?

[Brett Neumeier]

[-- Attachment #1: Type: text/plain, Size: 2256 bytes --]

On Fri, May 31, 2019 at 4:21 AM Laurent Bercot <ska-supervision@skarnet.org>
wrote:

> >I just attempted to link an apache24 instance to its log files via a
> >bundle, which isn't acceptable to s6-rc-compile.
> My advice is to use s6-rc's producer/consumer mechanism for one
> of the log streams, and use a named pipe for the other one, without
> cramming it into the s6-rc mechanism. That would typically mean:
>
> - configure apache24 to output its access log to stdout
> - declare apache24 as a producer for apache24-access-log and
> apache24-access-log as a consumer for apache24
> - apache24-access-log is a simple s6-log invocation, reading
> from its stdin
> - mkfifo /var/run/apache24/error-fifo (with appropriate rights)
> - declare that apache24 outputs its error log to
> /var/run/apache24/error-fifo
> - apache24-error-log has its run script doing something like:
> redirfd -r 0 /var/run/apache24/error-fifo s6-log your-logging-script
> - manually list apache24-error-log in apache24's dependencies, so
> apache24 doesn't start before apache24-error-log. (The pipeline
> mechanism automatically adds apache24-access-log to apache24's deps.)
> - manually define any bundles you want.
>

For what it's worth, I use approximately this setup on my s6- and
s6-rc-managed nginx server. The only difference is that I have nginx using
/dev/stdout as its _error_ stream; and then I have a service that creates a
separate fifo for each site defined in the nginx configuration. Nginx
writes each access log to the appropriate fifo, and there's a separate
s6-log process consuming from each of the fifos. I have had no problems
whatever with that setup, it works like a charm and was really pretty
straightforward to set up.

In fact, I find that there are a lot of services I want to run that can
either log to syslog or write to a specific filesystem location, and the
same "service writes to a fifo, s6-log reads from the fifo" mechanism works
fine for all of them. Since I use that pattern so frequently, I create a
`/run/log-fifos` directory to contain all the fifos. I think that makes the
entire mechanism pretty obvious and transparent, which is my general goal
with system administration.

Cheers,

Brett

-- 
Brett Neumeier (bneumeier@gmail.com)

Re: A better method than daisy-chaining logging files?

[Dewayne Geraghty]

On 31/05/2019 10:52 pm, Brett Neumeier wrote:
> On Fri, May 31, 2019 at 4:21 AM Laurent Bercot <ska-supervision@skarnet.org>
> wrote:
> 
>>> I just attempted to link an apache24 instance to its log files via a
>>> bundle, which isn't acceptable to s6-rc-compile.
>> My advice is to use s6-rc's producer/consumer mechanism for one
>> of the log streams, and use a named pipe for the other one, without
>> cramming it into the s6-rc mechanism. That would typically mean:
>>
>> - configure apache24 to output its access log to stdout
>> - declare apache24 as a producer for apache24-access-log and
>> apache24-access-log as a consumer for apache24
>> - apache24-access-log is a simple s6-log invocation, reading
>> from its stdin
>> - mkfifo /var/run/apache24/error-fifo (with appropriate rights)
>> - declare that apache24 outputs its error log to
>> /var/run/apache24/error-fifo
>> - apache24-error-log has its run script doing something like:
>> redirfd -r 0 /var/run/apache24/error-fifo s6-log your-logging-script
>> - manually list apache24-error-log in apache24's dependencies, so
>> apache24 doesn't start before apache24-error-log. (The pipeline
>> mechanism automatically adds apache24-access-log to apache24's deps.)
>> - manually define any bundles you want.
>>
> 
> For what it's worth, I use approximately this setup on my s6- and
> s6-rc-managed nginx server. The only difference is that I have nginx using
> /dev/stdout as its _error_ stream; and then I have a service that creates a
> separate fifo for each site defined in the nginx configuration. Nginx
> writes each access log to the appropriate fifo, and there's a separate
> s6-log process consuming from each of the fifos. I have had no problems
> whatever with that setup, it works like a charm and was really pretty
> straightforward to set up.
> 
> In fact, I find that there are a lot of services I want to run that can
> either log to syslog or write to a specific filesystem location, and the
> same "service writes to a fifo, s6-log reads from the fifo" mechanism works
> fine for all of them. Since I use that pattern so frequently, I create a
> `/run/log-fifos` directory to contain all the fifos. I think that makes the
> entire mechanism pretty obvious and transparent, which is my general goal
> with system administration.
> 
> Cheers,
> 
> Brett
> 

Thank-you both for your sound advise.  I did in fact implement Laurent's
suggestions, unfortunately I was a flu early-adopter here in Australia.

Brett, I think I'm more on the same page now and upon reflection, my
question was pretty much a newbie as I'd failed to fully grasp that that
s6-rc is not independent of s6 and that s6 dependencies are my friend
which they now are.

My setup is a little more complicated.  I have FreeBSD jails running the
service, and create a shared mount point where the service runs within
the jail, communicates to a nullfs device where the fifo queue resides.
 It all works nicely until there is a rotation, which I induce with
# s6-svc -a /run/scan/apache24-error-log

The result is a directory containing
-rw-r--r--  1 mylogger  www     0B Jun 17 15:34 state
-rw-r--r--  1 mylogger  www     0B Jun 17 15:34 lock
-rwxr--r--  1 mylogger  www   329B Jun 17 15:34 previous
-rw-r--r--  1 mylogger  www     0B Jun 17 15:34 current

and an error message
s6-log: warning: unable to finish previous .s to logdir
/var/log/httpd/error: Operation not permitted

I've su'ed into the /var/log/httpd/error as "logger" and I'm able to
create and compress files within the directory; so there are no
permission issues.  And both execlineb and s6-log are installed with 766
privs.

Does s6-log require root:wheel privs to perform functions within the log
directory?


FYI: and largely for those trying to use *BSD and slightly challenging
setup:
The final logger is

#!/usr/local/bin/execlineb -P
s6-setuidgid mylogger
redirfd -r 0 /m/jail3/fifo/apache24-error
s6-log -b n14 r7000 s100000 S3000000 /var/log/httpd/error
# /m is specially mounted and accessible. :)

And the apache24 httpd.conf contains
ErrorLog "/fifo/apache24-error"

For *BSD folks
mkdir -p /m/jails3/fifo /jails/jail3/fifo
mount -t nullfs /m/jail3/fifo /jails/jail3/fifo

Kind regards, Dewayne

Re: A better method than daisy-chaining logging files?

[Laurent Bercot]

># s6-svc -a /run/scan/apache24-error-log
>
>The result is a directory containing
>-rw-r--r--  1 mylogger  www     0B Jun 17 15:34 state
>-rw-r--r--  1 mylogger  www     0B Jun 17 15:34 lock
>-rwxr--r--  1 mylogger  www   329B Jun 17 15:34 previous
>-rw-r--r--  1 mylogger  www     0B Jun 17 15:34 current
>
>and an error message
>s6-log: warning: unable to finish previous .s to logdir
>/var/log/httpd/error: Operation not permitted
>
>I've su'ed into the /var/log/httpd/error as "logger" and I'm able to
>create and compress files within the directory; so there are no
>permission issues.  And both execlineb and s6-log are installed with 766
>privs.

You mean "mylogger", I assume? Does the mylogger user belong
to the www group?
What are the permissions on the /var/log/httpd/error directory
itself?
Can you send a strace, or a kdump/ktrace, of the s6-log process
when the error occurs? One of the system calls performed during a
rotation is failing with EPERM and knowing which one will help us
pinpoint exactly what's going wrong.


>Does s6-log require root:wheel privs to perform functions within the log
>directory?

No, if the logdir belongs to the user s6-log is running as, and has
at least S_IRWXU permissions, then s6-log is good to go. Something else
is going on here, and knowing what syscall is failing will tell us
where to look.

--
Laurent

Re: A better method than daisy-chaining logging files?

[Dewayne Geraghty]

Laurent, if you keep this up, I'm going to think you're mystical.

Putting mylogger into the www group did fix the "problem".  And not
without a sigh of relief!

FYI: The fifo queue permissions, which the jail sees
pr---w----  1 mylogger  www     0B May 31 13:27 apache24-error|

The final log repository, in the logging jail
# ls -lrth /var/log/httpd/error
-rw-r--r--  1 mylogger  www     0B Jun 18 07:43 state
-rw-r--r--  1 mylogger  www     0B Jun 18 07:43 lock
-rw-r--r--  1 mylogger  www     0B Jun 18 07:43 current
-rwxr--r--  1 mylogger  www   329B Jun 18 07:43 @400000005d08099e33134f4c.s*
but now with
www:*:80:mylogger

Thank-you.
Regards, Dewayne
PS. I'll investigate the u:x and o:r permissions later.

Re: A better method than daisy-chaining logging files?

[Laurent Bercot]

>FYI: The fifo queue permissions, which the jail sees
>pr---w----  1 mylogger  www     0B May 31 13:27 apache24-error|

Ah, so the www group is the one that writes to the fifo. Got it.

Then you don't need mylogger to belong to the www group (and
it's probably better for privilege separation that it doesn't),
but you apparently need the logdir to belong to the primary group
of the mylogger user. There is no reason for the logdir to belong
to the www group.

The error you got still strikes me as weird, and shouldn't happen
unless you have strange permissions for the logdir itself, or
FreeBSD is doing something wonky with gid checking. For my peace
of mind, I'd still like to see the permissions on your logdir,
and a ktrace of the error.

--
Laurent

Re: A better method than daisy-chaining logging files?

[Dewayne Geraghty]

Sure.  I don't think the permissions are particularly weird? ;)

Remember we're effectively talking about two VM's one running apache and
the other being a log recipient, so priv's aren't a big deal in this
latter's context.  On the logger, the files, as requested are:

# ls -lrth /var/log/httpd | grep error ; ls -lrth  /var/log/httpd/error
drwx------  2 mylogger  www   512B Jun 18 15:06 error/
total 44
-rw-r--r--  1 mylogger  www     0B Jun 18 15:06 state
-rw-r--r--  1 mylogger  www     0B Jun 18 15:06 lock
-rw-r--r--  1 mylogger  www    41K Jun 18 16:04 current

When I send
s6-svc -a /run/scan/apache24-error-log
the processor does its job correctly.

And while the systems are all running, and simply remove mylogger from
the www group, then sending an alarm to the service works correctly.

-rw-r--r--  1 mylogger  www     0B Jun 18 15:06 lock
-rwxr--r--  1 mylogger  www   2.7K Jun 18 16:59 @400000005d088c11012cc9f4.s*
-rw-r--r--  1 mylogger  www     0B Jun 18 17:03 state
-rw-r--r--  1 mylogger  www     0B Jun 18 17:03 current
-rwxr--r--  1 mylogger  www    64B Jun 18 17:03 @400000005d088cd6113d5a5c.s*

However when I remove mylogger from the www group and restart (into a
relatively pristine test environment), it all works well but we return
to the original problem:

# s6-svc -a /run/scan/apache24-error-log
                             # lh /var/log/httpd | grep error ; lh
/var/log/httpd/error
drwx------  2 mylogger  www   512B Jun 18 17:05 error/
total 4
-rw-r--r--  1 mylogger  www     0B Jun 18 17:04 lock
-rw-r--r--  1 mylogger  www     0B Jun 18 17:05 state
-rwxr--r--  1 mylogger  www   304B Jun 18 17:05 processed*
-rw-r--r--  1 mylogger  www     0B Jun 18 17:05 current

with the resulting
s6-log: warning: unable to finish processed .s to logdir
/var/log/httpd/error: Operation not permitted

This is on a box that lacks development tools, so tracing will take some
time to sort out; sorry. :/

FreeBSD does have tweakable knobs to prevent seeing other uids or gids
which were enabled, but disabling made no difference (I thought we were
onto something for a minute there).
Cheers, Dewayne

Re: A better method than daisy-chaining logging files?

[Joan Picanyol i Puig]

* Laurent Bercot <ska-supervision@skarnet.org> [20190618 08:22]:
> >FYI: The fifo queue permissions, which the jail sees
> >pr---w----  1 mylogger  www     0B May 31 13:27 apache24-error|
> 
> Ah, so the www group is the one that writes to the fifo. Got it.
> 
> Then you don't need mylogger to belong to the www group (and
> it's probably better for privilege separation that it doesn't),
> but you apparently need the logdir to belong to the primary group
> of the mylogger user. There is no reason for the logdir to belong
> to the www group.
> 
> The error you got still strikes me as weird, and shouldn't happen
> unless you have strange permissions for the logdir itself, or
> FreeBSD is doing something wonky with gid checking.

He is nullfs mounting some of these directories, wonkyness might happen.

> For my peace of mind, I'd still like to see the permissions on your
> logdir, and a ktrace of the error.

* Dewayne Geraghty <dewayne.geraghty@heuristicsystems.com.au> [20190618 09:16]:
> On the logger, the files, as requested are:
> 
> # ls -lrth /var/log/httpd | grep error ; ls -lrth  /var/log/httpd/error
> drwx------  2 mylogger  www   512B Jun 18 15:06 error/
> total 44
> -rw-r--r--  1 mylogger  www     0B Jun 18 15:06 state
> -rw-r--r--  1 mylogger  www     0B Jun 18 15:06 lock
> -rw-r--r--  1 mylogger  www    41K Jun 18 16:04 current
[...]
> -rw-r--r--  1 mylogger  www     0B Jun 18 15:06 lock
> -rwxr--r--  1 mylogger  www   2.7K Jun 18 16:59 @400000005d088c11012cc9f4.s*
> -rw-r--r--  1 mylogger  www     0B Jun 18 17:03 state
> -rw-r--r--  1 mylogger  www     0B Jun 18 17:03 current
> -rwxr--r--  1 mylogger  www    64B Jun 18 17:03 @400000005d088cd6113d5a5c.s*
> 
[...]
> # s6-svc -a /run/scan/apache24-error-log
>                              # lh /var/log/httpd | grep error ; lh
> /var/log/httpd/error
> drwx------  2 mylogger  www   512B Jun 18 17:05 error/
> total 4
> -rw-r--r--  1 mylogger  www     0B Jun 18 17:04 lock
> -rw-r--r--  1 mylogger  www     0B Jun 18 17:05 state
> -rwxr--r--  1 mylogger  www   304B Jun 18 17:05 processed*
> -rw-r--r--  1 mylogger  www     0B Jun 18 17:05 current

Include -a to your ls flags, to show the directory's permissions for
completeness.

> with the resulting
> s6-log: warning: unable to finish processed .s to logdir
> /var/log/httpd/error: Operation not permitted
> 
> This is on a box that lacks development tools, so tracing will take some
> time to sort out; sorry. :/

Just add 

ktrace -id -f /var/tmp/s6-log.trace

before your s6-log invocation and send the output of

kdump -f /var/tmp/s6-log.trace

afterwards.

qvb
--
pica

Re: A better method than daisy-chaining logging files?

[Dewayne Geraghty]

Thanks Joan, I appreciate the advise, unfortunately the box I'm working
returns:

# ps -axw | grep s6-l|grep erro
83417  -  Is         0:00.01 s6-log n14 r7000 s100000 S3000000 n14 -.*
+fatal: 2 -.* +^STAT =/var/log/httpd/error/status f !/usr/bi

# ktrace -f /tmp/s-log.txt -p 83417
ktrace: /tmp/s-log.txt: Function not implemented

Its a preproduction box, everything optimised and stripped (no debug
symbols).

I've worked with nullfs since 2004, probably a little delicate then, but
I've used extensively on customer sites and its proven to be ok. :)  The
nullfs component is where the files are piped through, and not the
end-point destination which is ufs2 on an SSD.
Regards, Dewayne.

Re: A better method than daisy-chaining logging files?

[Joan Picanyol i Puig]

* Dewayne Geraghty <dewayne.geraghty@heuristicsystems.com.au> [20190618 09:38]:
 
> # ktrace -f /tmp/s-log.txt -p 83417
> ktrace: /tmp/s-log.txt: Function not implemented
> 
> Its a preproduction box, everything optimised and stripped (no debug
> symbols).

Apparently you've stripped 

options KTRACE

from your kernel config. Boot GENERIC just for this test.

> I've worked with nullfs since 2004, probably a little delicate then, but
> I've used extensively on customer sites and its proven to be ok. :)  The
> nullfs component is where the files are piped through, and not the
> end-point destination which is ufs2 on an SSD.

oh, ok, probably safe then

regards
--
pica

Re: A better method than daisy-chaining logging files?

[Dewayne Geraghty]

Thanks Pica.  I've sent the ktraces to Laurent and will update when
possible.

Re: A better method than daisy-chaining logging files?

[Laurent Bercot]

[-- Attachment #1: Type: text/plain, Size: 694 bytes --]


>Thanks Pica.  I've sent the ktraces to Laurent and will update when
>possible.

  Please send your mails to the mailing-lists, not to me personally.
I'm not always available for help, but other people on the mailing-list
may be. For large files (such as traces), you can pastebin them
somewhere, and send the link to the ML.

  I have not received the e-mails you sent me because you did not
answer the confirmation request. I tried to contact you off-list,
but your ISP is refusing mails coming from my ISP (that's a first,
and sending mails through my ISP's MTA is *already* a mail failure
mitigation strategy, so at this point I'm not sure I could do more.)

--
  Laurent

Re: A better method than daisy-chaining logging files?

[Dewayne Geraghty]

Good point.
# ls -lrtha /var/log/httpd | grep error; ls -lrtha /var/log/httpd/error"
drwx------   2 mylogger  www     512B Jun 18 17:31 error
total 12
-rw-r--r--  1 mylogger  www     0B Jun 18 17:31 state
-rw-r--r--  1 mylogger  www     0B Jun 18 17:31 lock
drwxrwxrwx  6 mylogger  www   512B Jun 18 17:31 ..
drwx------  2 mylogger  www   512B Jun 18 17:31 .
-rw-r--r--  1 mylogger  www   329B Jun 18 17:32 current

Reflects my effort in previous testing that I forgot to reset! :)
And there are no mandatory security labels in effect, for completeness ;)