Re: Sometimes multilog rotates the logfile when receiving a sigterm

(* 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.

> 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.

> 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.  

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.

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
setsid() before exec'ing multilog (ala "Bernstein chaining"), or if
you're running under Linux possibly use the setsid command (I've not
tried this as I don't have a daemontools environment under Linux to
test, and my setsid here appears to be doing an undocumented fork()
as well).


-- 
Regards,
  Daryl Tester

"Crush! Kill! Deploy!"  -- Lost In Space I.T. Dept.