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

[feature] : Reduce command line output for info logging level #929

Closed
MaxGamill-Sheffield opened this issue Oct 3, 2024 · 5 comments · Fixed by #976
Closed

[feature] : Reduce command line output for info logging level #929

MaxGamill-Sheffield opened this issue Oct 3, 2024 · 5 comments · Fixed by #976
Labels
enhancement New feature or request Low Priority

Comments

@MaxGamill-Sheffield
Copy link
Collaborator

Is your feature request related to a problem?

Much of the command line output for TopoStats is not required for observing the running of a TopoStats workflow by the user, and the sheer number of lines makes it difficult to see error or warning logs too.

This has already been done for the topology branch and its associated steps (disordered_tracing, nodestats, ordered_tracing, and splining).

Describe the solution you would like.

I have already amended the output in the "dnatracing" section to only include the module name and the number of things it's processing as this can change throughout the processing:

***<Module>***
[<filename>] : Obtaining <outputs> from <N> grains.

Any broad except statements contain the step its stopped, the grain it's stopped for, and the traceback of the error:

except Exception as e:
	LOGGER.error("Error processing <step> for <n> grain. Consider raising an issue on the GitHub. Error: ", exec_out=e)

Everything else is moved to LOGGER.debug()

Describe the alternatives you have considered.

No response

Additional context

No response

@MaxGamill-Sheffield MaxGamill-Sheffield added the enhancement New feature or request label Oct 3, 2024
@ns-rse ns-rse changed the title [feature] : Reduced command line output for info logging level [feature] : Reduce command line output for info logging level Oct 4, 2024
@ns-rse
Copy link
Collaborator

ns-rse commented Oct 4, 2024

How many people beyond those developing care at all about the output?

I'm not sure making everything DEBUG is the correct approach here. Perhaps, currently we use DEBUG when we want really detailed information out.

Having a --quiet/-q flag to suppress all output would be one option (in essence this would set the log-level to WARNING log-level) would be more appropriate (and considerably easier to implement across the code base).

After all whilst a batch of images are processing there is no need to sit and watch the progress bar and the time can be used productively elsewhere1

XKCD #303 Compiling

@SylviaWhittle mentioned she had some thoughts on overhauling logging, what are your thoughts?

I quite like loguru which has been used in AFMReader and wouldn't mind switching to that.

Footnotes

  1. I'm currently waiting for analyses to run on my other project and am writing slides for SheffieldR User Group meeting this evening, looking at the pytest error in Performance regression of Topoly with Python 3.12 #927 and reading issues here, but that is only because I'm in the office and don't have my toy sword to hand!

@MaxGamill-Sheffield
Copy link
Collaborator Author

So the experimentalists here say that:

  • no output at all would be detrimental as they'd not be sure how things are going.
  • Their favourite message is the final one.
  • Currently there is too much output that they don't care about at all, and it goes too fast to read.

I pitched my solution to show only the bits mentioned above and they like that. So maybe if there is another, not debug, channel of the logger we could use that'd be ace.

What's the key differences between what we use now and loguru?

@ns-rse
Copy link
Collaborator

ns-rse commented Oct 4, 2024

Just setting the log-level to WARNING would achieve the verbosity that is being proposed I think. Would need to tweak the end message to ensure its always shown...

If people/users need some indication of progress is required we already use tqdm which shows a progress bar which is mostly occluded/battered by the verbose logging and so reducing output should make that more visible.

(topostats-311) ❱ topostats process --log-level warning
[Fri, 04 Oct 2024 12:13:15] [INFO    ] [topostats] Updated config config[log_level] : info > warning 
Processing images from /home/neil/work/git/hub/AFM-SPM/TopoStats, results are under output:   0%|                                        | 0/1 
[00:00<?, ?it/s][Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'topology_flip' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'topology_flip' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'confidence' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'confidence' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'confidence' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'confidence' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'confidence' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'confidence' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Item 'confidence' is None. Skipping.
[Fri, 04 Oct 2024 12:13:42] [WARNING ] [topostats] Cannot save key 'confidence' to HDF5. Item type: <class 'NoneType'>. Skipping. One of data, shape or dtype must be specified
Processing images from /home/neil/work/git/hub/AFM-SPM/TopoStats, results are under output: 100%|████████████████████████████████| 1/1 [00:26<00:00, 26.49s/it]

Note the progress bar at the end (and the omission of the summary).

loguru simplifies a lot of the boiler-plate code involved in logging. For example and relevant to the current situation/discussion...

Fully descriptive exceptions

Logging exceptions that occur in your code is important to track bugs, but it’s quite useless if you don’t know why it failed. Loguru helps you identify problems by allowing the entire stack trace to be displayed, including values of variables (thanks better_exceptions for this!).

@MaxGamill-Sheffield
Copy link
Collaborator Author

Oh that's interesting, I've found you can do that with the logger we have at the moment by specifying the error of the except statement by passing to an exec_out argument but it could be nicer.

With the warning level, I believe some of the logging is useful like telling you how many images have been found for processing / where processing is being input to / output from and hence I thought this would classify as info whereas things like the polynomial coefficients of flattening is more debug?

@ns-rse
Copy link
Collaborator

ns-rse commented Oct 7, 2024

For the time being I think this should go into the backlog as we need to focus on the functionality being merged and a new version realeased.

I've still got quite a few broken tests to investigate and resolve.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request Low Priority
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants