Is there a way to get std-nslog to log only the log message and not log the timestamp / app name / etc on each line?

[michelcrypt4d4mus]

when my briefcase app prints stuff the lines are always prepended with many characters worth of metadata, e.g. here's code in my app printing some env vars:

from os import environ
from sys import stderr

to_stderr = lambda msg: print(msg, file=stderr)


to_stderr("------------\n| ENVIRONMENT |\n--------------")

for k in sorted(environ.keys()):
    if k.startswith("SH"):
        to_stderr(f"{k}: {environ[k]}")

that yields this output in macos Terminal:

2024-07-03 03:11:24.741 IllmaticApp[59408:12767952] ---------------
2024-07-03 03:11:24.741 IllmaticApp[59408:12767952] | ENVIRONMENT |
2024-07-03 03:11:24.741 IllmaticApp[59408:12767952] ---------------
2024-07-03 03:11:24.743 IllmaticApp[59408:12767952] SHELL: /bin/bash
2024-07-03 03:11:24.743 IllmaticApp[59408:12767952] SHLVL: 1

is there some way to configure the app or std-nslog or whatever so that it would only send this to STDOUT? for reference this would be the output i'd be going for from the same code:

---------------
| ENVIRONMENT |
---------------
SHELL: /bin/bash
SHLVL: 1

[michelcrypt4d4mus]

i seem to have answered my own question but found some unexpected edge cases in the process that probably are not bugs. building my app with console_app=true got rid of all the timestamp etc. cruft on my app's output at least when printing to STDERR just as i was hoping. but two things:

1. it only works for stderr? the to_stderr lambda in the code above is able to print clean lines with no timestamps but a standard print() still has the timestamps and other junk
2. anything printed to stdout or stderr before the app enters main() still has the timestamp etc cruft.

re: 2) my app happens to use standard python ArgumentParser. the code above is triggered by something like this from Terminal:

/Applications/IllmaticApp/Contents/MacOS/IllmaticApp --print-env

and everything it prints via to_stderr() is without the timestamp etc. prefix as i want. however when i use default --help option provided by ArgumentParser all of a sudden all the crufty timestamps are back. the reason seems to be that i was calling parse_args() before the app entered main(), like this: (actually that's not it; see below)

parser = ArgumentParser(description=f"Help screen")
parser.add_argument('--print-env', action='store_true', help=f"print env vars")
args = parser.parse_args()

def main():
    if args.print_env:
       print_env()

parse_args() will short circuit execution and exit if it detects --help so i guess whatever console_log=true magic needs to happen to get rid of the timestamp cruft has not kicked in before the main() function starts executing.

UPDATE i moved the call to parse_args() inside of main() and nothing changed as far as --help triggering the timestamp cruft to reappear so maybe this is a very corner case bug?

[mhsmith]

OK, @freakboy3742 knows more than me about this area, so he can probably help you when he gets back from his break in a few days.

[michelcrypt4d4mus]

mysteriously after some unrelated changes to my app i now get the full timestamp noise even on stderr, so whatever was happening before where the noise was successfully suppressed is no longer happening. i haven't looked into it in depth but one change i know i made was moving import nslog to before the imports of my custom packages (my briefcase app is almost entirely in a custom package; the briefcase part just wraps calls to the package) whereas before the import nslog came after my imports (i think).

the inconsistent behavior makes me suspect it's more likely to actually be a bug, though i'm also not actually sure i should be importing nslog at all when console=true?

also maybe worth mentioning that it's only python code in the briefcase app that gets the timestamp cruft. the imported package code is able to log without it to all streams (files, stdout, stdin) with all the colors rich provides and without the extra noise and has been able to since the beginning, before i even configured my briefcase app with console=true.

[freakboy3742]

Some clarifications:

The timestamp prefix isn't being added by Toga, Briefcase, or std-nslog. It's a feature of the macOS/iOS system log; and this logging hander is installed before any user code is executed.

When you run a GUI app with briefcase run, Briefcase should be filtering the logging prefix. If it isn't, then the regex isn't matching for some reason.

If you run the GUI app using open build/myapp/macos/app/My App.app, then you won't get any console output at all - open will return immediately.

If you're running a GUI app by invoking the binary directly (i.e., ./build/myapp/macos/app/My\ App.app/Contents/MacOS/My\ App), then you will see the log prefix... but that's also an "off script" way to start a GUI app. In this usage, what you're seeing is the NSLog output that would ordinarily be output to the system log.

If you add console=True to your app configuration, std-nslog isn't used at all unless your code is explicitly importing it. The stub binary for a console app doesn't install look for or install a logging hook.

If you've been moving back and forth between console and non-console apps, it's possible you've got a GUI stub binary in an app that is currently configured as a console app. To be sure you've got a "clean" build, delete the build folder, and re-run briefcase create/build/run.

If your own code is including a call to import nslog, then you're getting exactly what you've asked for - NSLog-processed output on stdout and stderr. There's no need to manually import nslog, even in the GUI app case - Briefcase will automatically import nslog on GUI apps, and not import nslog on console apps.

The interaction with rich could be interesting, because rich is itself doing a bunch of weird stdout/err handling. I'd need to dig into details, but it's entirely possible it's not using sys.stdout, but sys.__stdout__, which is guaranteed to be the original file pointer. As such, anything that std-nslog is doing would be moot when it comes to rich managed output.

I don't know if that clarifies the behaviour you're seeing - it's a little hard to follow exactly what changes you've made in what order - but if you're seeing behavior that doesn't seem consistent with what I've described here, provide a reproduction case and I'll see what I can work out.

[michelcrypt4d4mus]

If your own code is including a call to import nslog, then you're getting exactly what you've asked for - NSLog-processed output on stdout and stderr. There's no need to manually import nslog, even in the GUI app case - Briefcase will automatically import nslog on GUI apps, and not import nslog on console apps.

thanks for the detailed explanation. i am indeed currently putting import nslog at the top of my app.py in the briefcase project (which i started before console=true was an option but have since converted) which based on what you say seems to explain the behavior. will do some more digging and report back if anything unexpected happens.

[michelcrypt4d4mus]

removing import nslog from app.py did the trick, thanks