Re: Sometimes multilog rotates the logfile when receiving a sigterm

2009/8/29 Daryl Tester <[email protected]>:
> (* Reply to /dev/null'd *)
>
> Rodrigo Campos wrote:
>
>>> Rotate to *.s, or *.u.  There is a race here - if the first program
>>> terminates quickly enough and closes the pipe, multilog may get
>>> the chance to clean up before receiving the signal.
>
>> hmm, could be.
>
> Well, it took me several runs before I saw the results you did.
> Without intensive observation, I'm putting it down to races.
>
>> Anyways, I've tried sending a SIGPIPE to multilog (what multilog
>> should receive if the process die, if I'm not wrong)
>
> If you mean the first process, no.  If the pipe is closed due to
> the write process exiting (either normally or abnormally) then
> multilog will receive EOF when attempting to read from the pipe.
> SIGPIPE is received by the writing process when attempting to
> write to the pipe when the *reader* has gone away.

Yes, you are right. Sorry

>
>> and it happens that the file is rotated with .u extension (and
>> without running it an other time).
>
> $ mkdir TEST1
> $ (sleep 1; ls -l TEST1 >&2; sleep 40) | multilog ./TEST1
> # Note: multilog is still running at this point
> total 0
> -rw-r--r--  1 dt  wheel  0 Aug 29 17:47 current
> -rw-------  1 dt  wheel  0 Aug 29 17:47 lock
> -rw-r--r--  1 dt  wheel  0 Aug 29 17:47 state
> ^C
> $ ls -l TEST1
> total 0
> -rw-r--r--  1 dt  wheel  0 Aug 29 17:47 current
> -rw-------  1 dt  wheel  0 Aug 29 17:47 lock
> -rw-r--r--  1 dt  wheel  0 Aug 29 17:47 state
>
> $ (sleep 1; ls -l TEST1 >&2; sleep 40) | multilog ./TEST1
> # Note: Multilog has rotated current to *.u due to funky current perms
> total 0
> -rw-r--r--  1 dt  wheel  0 Aug 29 17:47 @400000004a98e5cd368417c4.u
> -rw-r--r--  1 dt  wheel  0 Aug 29 17:54 current
> -rw-------  1 dt  wheel  0 Aug 29 17:47 lock
> -rw-r--r--  1 dt  wheel  0 Aug 29 17:54 state
>
> # Wait until multilog has terminated
> $ ls -l TEST1
> total 0
> -rw-r--r--  1 dt  wheel  0 Aug 29 17:47 @400000004a98e5cd368417c4.u
> -rwxr--r--  1 dt  wheel  0 Aug 29 17:54 current
> -rw-------  1 dt  wheel  0 Aug 29 17:47 lock
> -rw-r--r--  1 dt  wheel  0 Aug 29 17:54 state
>
> current's permissions show that multilog has terminated normally.
>
> If you're getting different results, then you need to show what
> steps you are performing to get those results.

No I'm getting the same results in my machine too

>
>> I've thought that perhaps it should handle SIGPIPE as a SIGTERM, I
>> made a patch at work, but... it was friday, I didn't test it and... go
>> home :). What do you think about handling SIGPIPE as a SIGTERM ?
>
> See above regarding signals.

Yes, Thanks :)

> Again, remember that you're running multilog from the command line,
> which *isn't how it's normally run*, so you're seeing and trying to
> correct behaviour that would normally not be an issue.  multilog
> typically runs under supervise, which never randomly sends SIGINT
> to its child processes.

Ahh, I understand.

It happens on some machine I do not have access right now, I will
investigate further if any signal its getting to multilog or something
like that.

>
> Personally, if I were to write something to work around this behaviour
> I would write a nohup-style wrapper that blocks SIGHUP or performs a

Yes, perhaps running "<program> | (trap ...; multilog...)" makes the
trick (nohup if that is the signal, but trap if its other signal).
Will try something like that, thanks :)

Or perhaps I can always send a SIGTERM to multilog first and then
SIGTERM to the program. Although avoiding the signals to arrive to
multilog seems to be what I really want (if that is what is causing it
to generate the .u files I'm seeing).

An other option perhaps is running it through a fifo (mkfifo).

Next week I will have access to the machines again, investigate
further what is happening and let you know =)




Thanks a lot,
Rodrigo