AFM-SPM / TopoStats

An AFM image analysis program to batch process data and obtain statistics from images
https://afm-spm.github.io/TopoStats/
GNU Lesser General Public License v3.0
58 stars 10 forks source link

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

Open MaxGamill-Sheffield opened 2 weeks ago

MaxGamill-Sheffield commented 2 weeks ago

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

ns-rse commented 2 weeks ago

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 elsewhere[^1]

[XKCD #303 Compiling](https://xkcd.com/303/)

@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.

[^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 #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 commented 2 weeks ago

So the experimentalists here say that:

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 commented 2 weeks ago

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 commented 1 week ago

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 commented 1 week ago

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.