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

Implement log console levels #7406

Merged
merged 26 commits into from Oct 26, 2019
Merged

Implement log console levels #7406

merged 26 commits into from Oct 26, 2019

Conversation

@jasongrout
Copy link
Contributor

@jasongrout jasongrout commented Oct 23, 2019

References

Fixes #7386

Code changes

Adds the notion of a log message severity level and ways to set the log to filter on these levels.

TODO:

  • Remove the cycling of log levels for the notebook output logging, i.e., revert
    f11300a

User-facing changes

Added a log level toolbar select to set the current log filtering mode, as well as coloring and tooltips for the timestamps to indicate log severity using the theme colors. Here are some screenshots showing how different severity levels are handled:

Screen Shot 2019-10-24 at 11 21 18 AM
Screen Shot 2019-10-24 at 11 22 54 AM
Screen Shot 2019-10-24 at 11 23 11 AM
Screen Shot 2019-10-24 at 11 23 24 AM
Screen Shot 2019-10-24 at 11 23 34 AM
Screen Shot 2019-10-24 at 11 23 50 AM

Here is what happens by default:

  • For messages that are handled by the notebook, we display at info severity. The idea is that the user will see these elsewhere, and they are by far the most common things, so let's not overwhelm the user with information they already know.
  • For messages that are not handled by the notebook (probably few and far between), log normal messages to warning (as in "Warning: you haven't seen this output, but you might want to") and log error messages to error (as in "Error: here is an error you have not seen")

(for ipywidgets, we'll do the same as the latter: normal messages get logged at warning level, error messages get logged at error level, since people won't see those messages by default either).

I think that is the best balance between giving the information to the user, and making it useful and actionable by not overwhelming them with things they already can see.

Backwards-incompatible changes

None for any released packages.

This does change the logging api for the unreleased log console package to include a level for each message.

@jupyterlab-dev-mode
Copy link

@jupyterlab-dev-mode jupyterlab-dev-mode bot commented Oct 23, 2019

Thanks for making a pull request to JupyterLab!

To try out this branch on binder, follow this link: Binder

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 23, 2019

This is still a work in progress, but shows the rudimentary functionality already.

@blink1073
Copy link
Member

@blink1073 blink1073 commented Oct 24, 2019

I did a quick pass of the current state, I like the direction.

@jasongrout jasongrout added this to the 2.0 milestone Oct 24, 2019
@blink1073
Copy link
Member

@blink1073 blink1073 commented Oct 24, 2019

I think it should say "Level:" or some other label. Even though I knew what to expect I had to think about what the dropdown meant.

image

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 24, 2019

I think it should say "Level:" or some other label. Even though I knew what to expect I had to think about what the dropdown meant.

+1. I was following the pattern for the cell type dropdown initially. I'll look at adding a label to the left.

jasongrout added 2 commits Oct 24, 2019
This is purely for debugging and testing, and should be reverted before merging.
@blink1073
Copy link
Member

@blink1073 blink1073 commented Oct 24, 2019

It also isn't updating when I change it - it stays showing as "Warning". Do we want to add an indicator of the log level between the timestamp and the message (like "[D]")?

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 24, 2019

Do we want to add an indicator of the log level between the timestamp and the message (like "[D]")?

Oh, good idea. I already am setting the color and title of the timestamp based on the log level. Check out the commit I just pushed, which for testing purposes cycles the notebook outputs between log levels, to see what it looks like currently. Here I am hovering over the orange Error message level one.

Screen Shot 2019-10-23 at 8 27 26 PM

@blink1073
Copy link
Member

@blink1073 blink1073 commented Oct 24, 2019

Pulling

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 24, 2019

I like the idea of inserting an information message in the log when the level changes, so you can easily see when the log switched filtering levels.

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 24, 2019

Probably like the timestamp, it would be a critical message so it displays always.

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 24, 2019

Or perhaps we should have a highest-priority message type that is "Log metadata messages" or something, for timestamps and these level change messages.

@blink1073
Copy link
Member

@blink1073 blink1073 commented Oct 24, 2019

I would think that would replace the "Add Timestamps" and be a radio button.

@blink1073
Copy link
Member

@blink1073 blink1073 commented Oct 24, 2019

Er, check box.

@blink1073
Copy link
Member

@blink1073 blink1073 commented Oct 24, 2019

I'm not sure about setting colors, that can get dicey with theming and accessibility

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 24, 2019

I'm not sure about setting colors, that can get dicey with theming and accessibility

I'm using the theme info/warning/error colors :)

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 25, 2019

@blink1073 - I've now reverted the automatic severity cycling I had in for debugging. Now what I implemented at https://github.com/jupyterlab/jupyterlab/pull/7406/files#diff-e8882401a823c162a5b87e72e58d3298R64-R73 takes effect:

  • For messages that are handled by the notebook - only display at info levels. The idea is that the user will see these elsewhere, and they are by far the most common things, so let's not overwhelm the user with information they already know.
  • For messages that are not handled by the notebook (probably few and far between), log normal messages to warning (as in "Warning: you haven't seen this output, but you might want to") and log error messages to error (as in "Error: here is an error you have not seen")

For ipywidgets, we'll do the same as the latter: normal messages get logged at warning level, error messages get logged at error level.

I think that is the best balance between giving the information to the user, and making it useful and actionable by not overwhelming them with things they already can see.

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 25, 2019

I don't know how to restart failed checks (I tried using the GitHub UX, but it didn't seem to do anything), so I pushed some whitespace changes to start a new CI run.

@mbektas
Copy link
Member

@mbektas mbektas commented Oct 25, 2019

@jasongrout I built and tested, this is looking great. I have some design related comments:

  • I was expecting levels to be just a filter, but they are acting as a lower limit. So, if level is set to Error and there are Info logs received, there is no way to see those info logs. I was expecting changing log level would just be filtering to that level. Also, I was hoping to combine logs from different levels (selecting both Warning and Error)
  • Do we need Critical and Debug levels? What would be the difference between Error and Critical? How would Debug be used in released product?
  • Google Chrome and Visual Studio have 3 levels and they can be combined
    vs

chrome

  • I noticed an issue with drop-down, when you hover on the label it highlights the dropdown but clicking label doesn't open the drop-down. Not specific to these changes I think, but still worth mentioning.
    LogLevels

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 25, 2019

I was expecting levels to be just a filter, but they are acting as a lower limit. So, if level is set to Error and there are Info logs received, there is no way to see those info logs. I was expecting changing log level would just be filtering to that level. Also, I was hoping to combine logs from different levels (selecting both Warning and Error)

All log messages are shown interleaved, sorted by timestamp. The dropdown controls the log filtering level, not the view filtering level. I think this is a fairly standard approach for logs (c.f. Python, Java logging, etc.), since storing all informational or debug messages can quickly overwhelm the system. (Filtering a view is also apparently a common approach, as you've pointed out.)

  • Do we need Critical and Debug levels? What would be the difference between Error and Critical? How would Debug be used in released product?

I adopted the levels from the Python logging system. I also looked at the Java logging system, which essentially has similar levels. I'm not very opinionated about these.

VS code looks like it has 4 levels? errors, warnings, info, and verbose?

  • I noticed an issue with drop-down, when you hover on the label it highlights the dropdown but clicking label doesn't open the drop-down. Not specific to these changes I think, but still worth mentioning.

Interesting. Likely this is standard browser behavior because the label is explicitly tied to the dropdown for accessibility.

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 25, 2019

  • Also, I was hoping to combine logs from different levels (selecting both Warning and Error)

The level you choose in the dropdown is the least important level to log. So you'll see that level and more important levels. (so selecting 'warning' logs critical, error, and warning messages).

@mbektas
Copy link
Member

@mbektas mbektas commented Oct 26, 2019

VS code looks like it has 4 levels? errors, warnings, info, and verbose?

If you are referring to capture I attached, that was from Google Chrome actually. Yes you are right, I was thinking Verbose was to enable the other three but indeed it is a separate one. Looks like there are so many flavors of log levels :)

Likely this is standard browser behavior because the label is explicitly tied to the dropdown for accessibility.

It turns out label hover changing state of dropdown is standard behavior. However, clicking the label is supposed to set focus to dropdown, interestingly it is not happening here.

@blink1073
Copy link
Member

@blink1073 blink1073 commented Oct 26, 2019

I'm good with the overall behavior now, but agree with @mbektasbbg about the label click behavior.

jasongrout added 2 commits Oct 26, 2019
This caused a helpful error in the console about not setting className to false.
We were too aggressive about activating the parent widget when getting a click in the toolbar. If we have a label for a control, clicking on the label by default focuses the control, which is what we want, but we were often wresting focus away from the control when we called the activate function.
@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Oct 26, 2019

clicking the label is supposed to set focus to dropdown, interestingly it is not happening here.

Turns out that the generic toolbar code was too aggressive about focusing the parent widget. This is fixed in the latest commit.

Copy link
Member

@blink1073 blink1073 left a comment

Nice work @jasongrout!

@blink1073 blink1073 merged commit fa0a5bc into jupyterlab:master Oct 26, 2019
7 of 9 checks passed
@blink1073
Copy link
Member

@blink1073 blink1073 commented Oct 26, 2019

@meeseeksdev backport to 1.x

@meeseeksdev
Copy link

@meeseeksdev meeseeksdev bot commented Oct 26, 2019

Owee, I'm MrMeeseeks, Look at me.

There seem to be a conflict, please backport manually. Here are approximate instructions:

  1. Checkout backport branch and update it.
$ git checkout 1.x
$ git pull
  1. Cherry pick the first parent branch of the this PR on top of the older branch:
$ git cherry-pick -m1 fa0a5bcb25635a71f7c33f46be77e96d531bfcb8
  1. You will likely have some merge/cherry-pick conflict here, fix them and commit:
$ git commit -am 'Backport PR #7406: Implement log console levels'
  1. Push to a named branch :
git push YOURFORK 1.x:auto-backport-of-pr-7406-on-1.x
  1. Create a PR against branch 1.x, I would have named this PR:

"Backport PR #7406 on branch 1.x"

And apply the correct labels and milestones.

Congratulation you did some good work ! Hopefully your backport PR will be tested by the continuous integration and merged soon!

If these instruction are inaccurate, feel free to suggest an improvement.

@wabiloo
Copy link

@wabiloo wabiloo commented Nov 19, 2019

Hi. Quick question...
I'm running JupyterLab 1.2.3.
How do I add my own debug logs for viewing in the log console, from my python code?

I tried

import logging
logging.debug("test")

and made sure that the dropdown in the log view is set to "Debug".

Other than .warning and .critical, no other method seems to be reflected in the logs

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Nov 19, 2019

Great question. This log is for front end things, so JLab extensions can log messages. One way to make it available to the kernel is to write a python package that sends log messages to JLab (perhaps as comm messages?) and also a JLab extension that takes those messages and puts them in the JLab log.

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Nov 19, 2019

Or perhaps this would be a great mimerender project. Define a mimetype for the rich display that renders the content to the JLab log.

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Nov 19, 2019

(short answer is that you can't do it right now. The above two comments give two ways you or someone else could extend JLab to make it possible.)

@agoose77
Copy link
Contributor

@agoose77 agoose77 commented Dec 12, 2019

@wabiloo I've written an extension to do this here. Let me know what you find!

@jasongrout
Copy link
Contributor Author

@jasongrout jasongrout commented Dec 12, 2019

Nice! Thanks for sharing!

@lock lock bot locked as resolved and limited conversation to collaborators Jan 12, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Linked issues

Successfully merging this pull request may close these issues.

5 participants