Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

FLOG, to replace debug() #5879

Merged
merged 7 commits into from May 28, 2019
Merged

Conversation

ridiculousfish
Copy link
Member

@ridiculousfish ridiculousfish commented May 19, 2019

This is a PR to get feedback on FLOG(), a proposed replacement for debug(). If others like this we'll migrate all uses of debug() to FLOG and then remove debug().

FLOG() is a function you call to log something that may be of interest to a user or developer trying to understand some behavior. FLOG improves on debug() in a few ways:

  1. Logs are no longer associated with a level, but instead with a category. For example "all job updates." This allows you to focus on the topic you're interested in.

  2. Categories can be independently toggled off and on.

  3. Log output can be redirected to a file (via a new command line option) independently of stderr.

Logging is simple and may be mechanically converted from debug():

 FLOGF(locale, L"locale var %s missing or empty", name.c_str());

there is also a non-format-string mode:

 FLOG(job, "Created job", j->job_id, "from command", j->command_wcstr(), "with pgrp", j->pgid);

Adding a new category is also very easy, just a one-line change in flog.h:

category_t job{L"job", L"Job status changes"};
category_t fork{L"fork", L"Calls to fork and why"};
category_t termowner{L"termowner", L"Changes to the terminal owner"};
category_t locale{L"locale", L"Changes to locale variables"};

To invoke fish with a log category enabled, we re-use the -d flag:

> fish -d jobs,locale

The -d option is treated as a wildcard, so you can glob. For example '*' will enable all categories.

You can say where you want the flog output to go:

> fish -d '*' --debug-output /tmp/output.txt

Lastly you can print all categories:

> fish --print-debug-categories
debug        Debugging aid (on by default)
fork         Calls to fork and why
job          Job status changes
locale       Changes to locale variables
ohno         Serious unexpected errors (on by default)
termowner    Changes to the terminal owner

@floam
Copy link
Member

floam commented May 19, 2019

What's the main reason to prefer a macro here over an inline function?

@floam
Copy link
Member

floam commented May 19, 2019

Maybe it'd be desirable to, instead of having a 'debug' and 'ohno' category, give it a concept of severity? Like err, warn, notice. e.g. FLOGF(job, err, "something went wrong in job handling"), FLOGF(job, notice, "job created").

I think we want to have some pretty output showing the category next to the message, and the severity could be indicated like debug() does, <E>, <W>, <N> and maybe even highlighted red, yellow, white.

@ridiculousfish
Copy link
Member Author

Thanks for your thoughtful ideas!

What's the main reason to prefer a macro here over an inline function?

The macro can avoid evaluating arguments, which might be expensive. With a function the arguments are always evaluated. That's why debug() is a macro.

Maybe it'd be desirable to, instead of having a 'debug' and 'ohno' category, give it a concept of severity? Like err, warn, notice. e.g. FLOGF(job, err, "something went wrong in job handling").

We should get away from severity levels - most logs aren't warnings or errors, they're just something normal that happened. And if they are warnings or errors we should print them.

The idea of ohno category (dumb name I admit) is to replace debug(0) calls, and the debug category is for debugging messages during development.

The big idea here is that we can log way more than we do today, because you have to opt into seeing the logs per-category.

I think we want to have some pretty output showing the category next to the message, and the severity could be indicated like debug() does, <E>, <W>, <N> and maybe even highlighted red, yellow, white.

Printing the category sounds good to me, still not sold on the severity level though. There's not really a severity associated with creating a job, etc.

@faho
Copy link
Member

faho commented May 19, 2019

Maybe it'd be desirable to, instead of having a 'debug' and 'ohno' category, give it a concept of severity?

One problem we've had for a while was that input had debug messages like "trying to match mapping" that were spamming on every single keypress, even if you weren't debugging input.

This would solve it by adding that to an "input" category. But what if you want to debug input, but not that particular part of input? You'd have to set it to a new category, and then you'd have to enable that category in addition to the others if you do want it.

That might turn out to be quite tricky. But on the other hand, we've never really nailed the severity levels.

What might help is:

  • Categories for error and warning that are on by default

  • Globbing for "subcategories" - "input-mapping" and "input-execute", activated via input*

If I'm reading this correctly, those are already in.

But that still means we need to come up with a sensible system of categories - you don't want to enable too much, and you want to be able to guess the category. I would default to the filename (minus the suffix), so you'd use "input", "input_common" and "builtin_cd", unless you wanted a more specific category (like termowner or "input-mapping").

Of course you could also make this much more elaborate (what about actual subcategories and multiple categories and....), but it's always easy to overengineer things.

I think we want to have some pretty output showing the category next to the message, and the severity could be indicated like debug() does, , , and maybe even highlighted red, yellow, white.

I love the idea of associating color with categories. Obviously we'd have to disable it if the term doesn't support it.

The idea of ohno category (dumb name I admit) is to replace debug(0) calls

Then why not call it "error"? debug(0) calls present <E> currently.

@zanchey
Copy link
Member

zanchey commented May 20, 2019

Having been a victim of various packages employing both a severity and category system, I strongly discourage this - it rapidly gets out of hand.

I like ohno because it reminds me of the noise Lemmings make when you used the bomb tool. I recognise this is not a strong reason for its use.

@floam
Copy link
Member

floam commented May 20, 2019

I believe he only spoke if you used the undo tool. Edit: oops, you said Lemmings, we’re not talking about Kid Pix here.

@faho faho added this to the fish-future milestone May 21, 2019
@faho
Copy link
Member

faho commented May 21, 2019

Fixes #4818, by the way.

This adds a new mechanism for logging, intended to replace debug().

The entry points are FLOG and FLOGF. FLOG can be used to log a sequence of
arguments, FLOGF is for printf-style formatted strings.

Each call to FLOG and FLOGF requires a category. If logging for a category
is not enabled, there is no effect (and arguments are not evaluated).

Categories may be enabled on the command line via the -d option.
@ridiculousfish ridiculousfish merged commit 0150d50 into fish-shell:master May 28, 2019
ridiculousfish added a commit that referenced this pull request May 28, 2019
This merges support for FLOG, a replacement for debug().

Fixes #5879
@ridiculousfish
Copy link
Member Author

I merged this as b9ef879

@ridiculousfish ridiculousfish deleted the flog branch May 28, 2019 02:01
@zanchey
Copy link
Member

zanchey commented May 28, 2019

The long option for -d is --debug-level, which is obviously not right for these new categories; perhaps we change it to just --debug? I presume the level arguments will stop working completely once FLOG is used everywhere.

@ridiculousfish
Copy link
Member Author

Sounds good, I'll file a thing.

@mqudsi
Copy link
Contributor

mqudsi commented Jun 9, 2019

This was sorely needed, thanks @ridiculousfish.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Apr 16, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants