[RPKI] routinator on NetBSD exiting unexpectedly

[Martin Hoffmann]

Hi Håvard!

Havard Eidnes wrote:
> 
> For some reason this one decides to exit after running a relatively
> short while, printing the single rather uninformative line
> 
> Logging to syslog failed: Format. Exiting.

That really isn’t helpful. I’ll check if there is a way to extract some
more details or removed the strange "Format" bit.

> However, the reason for this is apparently that routinator spews
> so many of those preceding "default_perms_for_dir: ... Operation
> not supported, falling back on umask" messages in quick
> succession, in fact so many that syslogd() doesn't manage to
> empty its end of /var/run/log quickly enough, and routinator gets
> the "ENOBUFS" error return.
> 
> I've tried to grep the routinator source for either "falling back
> on" or "default_perms_for_dir", but have come up empty so far.  Has
> someone gone to great lengths to make the source un-grep'able?  I
> thought rust programs compiled together all the sources with no
> dynamic linking of libraries, so the entire source code should be
> available in the build tree?

I think this message actually comes from the rsync binary. Which also
explains why these are sent in quick succession: We collect the rsync
output into a buffer and dump the whole thing (line by line) when rsync
returns. This has the advantage of keeping all the rsync output
together (given that there may be other things going on at the same
time).

So, a workaround would probably be to give a "-q" to rsync via the
rsync-args config file-only option. By default, it includes the 
"--contimeout=10" (if your rsync supports it) and "--max-size={}" where
{} is whatever the configured max-object-size is (20,000,000 by
default). So, the config file should include

| rsync-args = [ "-q", "--contimeout=10", "--max-size=20000000" ]

> Hm, yes...  Come to think of it, I have turned up the logging level
> to "debug", that obviously also doesn't help.  However, dialing that
> back to "info" or "warn" does not improve matters, setting it to
> "error" seems to have worked around this particular issue, but the
> "heartbeat" from routinator is now absent from the logs.

It indeed only suppresses the rsync output in log level error.
 
> Is there any way this can be improved on the routinator side?

One thing I can think of would be to only collect rsync’s stdout and
pipe stderr through immediately.

> I purposely avoid logging to a file, since I get log file rotation
> "for free" ("already configured") with syslog, and I've not checked
> whether routinator has any mechanism to do that rotation itself when
> logging directly to a file (doesn't look like it does from the
> supplied example config).

Sort of. We don’t have any explicit mechanism for rolling the file -- I
think typically you would want to use your system’s facilities for
that? -- but since 0.13.0 sending SIGUSR2 will now cause Routinator to
re-open the log file.

  -- Martin