Ideas / best practices for controlling verbosity in matlab functions

Question

Let's say I have some_fun that does some complicated work.

function foo = some_complicated_fun(x,y,z,verbosity)

I've written a good bit of debugging prints into this code, but the avg user may not be interested in seeing all that if it is working. Error statements (not enough args, etc) will print regardless.

My current method for writing a function is:

function foo = some_complicated_fun(x,y,z,verbosity)

(x,y,z,verbosity) = parse_args(x,y,z,verbosity); % parse args, check nargin, etc

for i=1:5, 

    % whatever    
    % do some work with x,y,z
    % blah blah

    if verbosity 
        fprintf('Now on iteration %i\n',i); % basic print
    end

    % or, with mutiple levels:
    if verbosity == 1;
        fprintf('Now on iteration %i\n',i); % basic print
    end
    if verbosity == 2;
        fprintf('x = %f,y = %f,z=%f %i\n',x,y,z); % more information
    end

    % do more work

end

I don't like doing it with the if statements because it clutters up the code, but I can't think of any other way. A one liner is better and worse:

if verbosity; fprintf('Iteration %i\n',i); end

Better because it's smaller, worse because one-liners are less readable than the same thing over 3 lines.

What I want is some simple, more elegant way to control verbosity.

Does that exist?

Answer 1

This is what I ended up doing.

I wrote a function (I called it vprintf, but there are better names.)

I'm not sure that I want to do global variables, but that's a thought.

function vprintf(v,l,varargin)
% VPRINTF(verbosity, verbosity_level_of_statement,sprintf_style_arguments
% 
% 
% example: 
% 
% verbosity = 1;
% vprintf(verbosity,1,'This will print if verbosity is at least 1\n Verbosity = %i\n',verbosity);

if nargin<3
    error('not enough arguments');
end
if v>=l % if verbosity level is >= level of this statment
%     keyboard;
    fprintf(varargin{:});
end

Answer 2

I have created a method to control log output verbosity. It is not finished yet, but since this question appeared I uploaded it to:

This link at Matlab File Exchange.

It works by setting global output log to the desired level, and will show the message on the following format:

OUTPUT_LEVEL:  function_which_called_message       Your_Message.

However, it will only output messages which are higher than the output level you set. The default is to display only INFO messages or higher, so it won't show DEBUG and VERBOSE messages. If you want to see debug messages, then you set:

Output.level(Output.DISP_DEBUG)

The Output methods are:

Output.VERBOSE
Output.DEBUG
Output.INFO
Output.WARNING
Output.ERROR 

You select the messages to be displayed in your functions by doing Output.'DESIRED_LEVEL'('message',input_1,input2) as in the sprintf or fprintf matlab format. I.e, Output.INFO('The variable value is %d',variable). For the WARNING and ERROR messages you may specify also the identifier, as 'PACKAGE:METHOD:ERROR_ID', and by doing so, the output will be on matlab's warning and error functions. I.e Output.WARNING('MY_PACKAGE:MY_METHOD:MY_ID','Something wrong happened here!').

The output levels available are:

Output.level(Output.DISP_VERBOSE) % Show all messages
Output.level(Output.DISP_DEBUG) % Show debug info warning errors
Output.level(Output.DISP_INFO) % Show info warning errors
Output.level(Output.DISP_WARNING) % Show warning errors
Output.level(Output.DISP_MUTE) % Show only errors.

You can also specify output to a log file by using

Output.place('file_path')

And replace log file (you can also use it to reset current log):

Output.place('file_path',true)

Or reset it to screen

Output.place(1)

Here is a sample of the output using output level DISP_VERBOSE:

>> nilmContainer = NilmFileContainer.newRun('inputFolder','sim_real/','runName','RealHouse','samplesPerFile',60*60*60);
VERBOSE: getFilesOnFolder               Found 2 files on folder 'data/sim_real/'. They are the following:
VERBOSE: getFilesOnFolder                   [1]:data/sim_real/240AM000.csv
VERBOSE: getFilesOnFolder                   [2]:data/sim_real/240AM001.csv
DEBUG:   NilmFileContainer.setRunName   Updating run name to RealHouse_Run5.
INFO:    newRun                         Reading file data/sim_real/240AM000.csv.
VERBOSE: csv_data                       Reading samples (Ignored:0,Read:216000,Remaining:2422014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_1-19:12:46-30_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:216000,Read:216000,Remaining:2206014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_2-20:12:45-30_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:432000,Read:216000,Remaining:1990014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_3-21:12:45-30_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:648000,Read:216000,Remaining:1774014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_4-22:12:45-30_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:864000,Read:216000,Remaining:1558014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_5-23:12:45-30_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:1080000,Read:216000,Remaining:1342014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_6-00:12:44-31_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:1296000,Read:216000,Remaining:1126014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_7-01:12:43-31_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:1512000,Read:216000,Remaining:910014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_8-02:12:43-31_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:1728000,Read:216000,Remaining:694014) at file: sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_9-03:12:43-31_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:1944000,Read:216000,Remaining:478014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_10-04:12:42-31_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:2160000,Read:216000,Remaining:262014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_11-05:12:41-31_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:2376000,Read:216000,Remaining:46014) at file: data/sim_real/240AM000.csv.
DEBUG:   addFiles                       Writing file 'data/NILM_DATA/RealHouse_Run5/RealHouse_Run5-File_12-06:12:41-31_10_2012.mat'
VERBOSE: csv_data                       Reading samples (Ignored:2592000,Read:46014,Remaining:0) at file: data/sim_real/240AM000.csv.
VERBOSE: csv_data                       Reading samples (Ignored:0,Read:169986,Remaining:2799058) at file: data/sim_real/240AM001.csv.
INFO:    readFile                       Found discontinuity while changing from file 'data/sim_real/240AM000.csv' to 'data/sim_real/240AM001.csv'.

As I said, it is not at the final version, but you can help me improve it! x)

Answer 3

Define a function to replace fprintf, that contains the if statement and the actual printing. And declare verbosity as a global variable, to avoid passing it as an argument every time.