markqvist / Reticulum

The cryptography-based networking stack for building unstoppable networks with LoRa, Packet Radio, WiFi and everything in between.
https://reticulum.network
MIT License
2k stars 124 forks source link

loglevel not respected #238

Closed gdt closed 1 year ago

gdt commented 1 year ago

To debug other issues, I set loglevel to 7 in ~/.reticulum/config, following the docs. I didn't get any log output other than the one "starting" message. By adding print statements to the log function it seems the loglevel variable is 3/warning. If I set the global to 7 in the sources (where it is 3), it still ended up 3. Adding a 'loglevel = 7' line to the log function allowed me to see logs.

I'm seeing this on NetBSD and macOS with 0.4.9.

markqvist commented 1 year ago

Are you running rnsd directly, or are you using some other program that sets its own loglevel? For example, nomadnet overrides the loglevel for its own particular RNS instance to the one set in ~/.nomadnetwork/logfile.

gdt commented 1 year ago

I am running rnsd directly. The logic around setting requested_loglevel is very confusing and that being set before config file parsing appears to lead to the config file level not being applied. I think the issue is that RNS init is being called with loglevel 3, from rnsd.py's startup which is asymmetric w.r.t. file and stdout.

gdt commented 1 year ago

I change the start of rnsd.py:program_setup to look like

    if service:
        targetlogdest  = RNS.LOG_FILE
        targetloglevel = None
    else:
        targetlogdest  = RNS.LOG_STDOUT
        targetloglevel = None

where the last line is new, and now my log level is respected.

gdt commented 1 year ago

I am guessing this is intended, to have rnsd with no args not use the configured loglevel but instead make it depend on the documented -v flag. As a new user, this feels like a bug; the docs say to change logging you adjust the config file, and that seems natural.

markqvist commented 1 year ago

Yeah, this is a bit confusing. I'll try and rethink this to see if there's a better way to do it.

gdt commented 1 year ago

Here's my perspective coming to this, not really 100% paying attention, with a long history of using many other things.

Given a program with a config file that can set loglevel, I expect it to use that loglevel when started, both in the foreground and when it is given the flag to daemonize. (Actually I expect it to daemonize automatically unless given a flag to stay in the foreground like -d or -N, but if the man page says what the flags do that's fine.) I am not surprised by a command-line arg to set the level, but I am very surprised by either of the foreground/background invocations just not respecting the level.

I find the "nomadnet has rnsd in it" sensible but unusual so I don't quite have expectations. I do expect the nomadnet man page to be very clear about whether the rnsd config file applies or whether there is somehow config in nomadnet. Actually on reflection I expect the rnsd config to be used, so starting rnsd and using it vs not starting it gets you the same behavior.

I also expect programs, when in the background as daemons, to log to syslog.

Finally, and sort of off topic for logging, I find that rnsd is sort of a system daemon, sort of a per-user daemon ,and sort of a foreground program. I feel that this needs to be articulated and straightened out, so that even if all are possible, it's clearly in some mode and is aligned to that mode. For example if I run rnsd under my uid I do not expect it to look for /etc/reticulum/anything.

Hope this helps as a perspective from someone who didn't already understand.

gdt commented 1 year ago

Also, the (unix) norm is LOG_FOO always in the code, with syslog deciding what to print, and the -D flag is about shades of LOG_DEBUG. Not saying you should pivot, just that some will have that expectation.

gdt commented 1 year ago

Concretely, I suggest:

markqvist commented 1 year ago

Thanks for the insights! Very helpful!