Back to the main page.
Bug 1686 - improve debugging of end-users problems using logging options
| Status | CLOSED FIXED |
| Reported | 2012-09-02 12:19:00 +0200 |
| Modified | 2019-08-10 12:29:28 +0200 |
| Product: | FieldTrip |
| Component: | core |
| Version: | unspecified |
| Hardware: | PC |
| Operating System: | Mac OS |
| Importance: | P5 enhancement |
| Assigned to: | |
| URL: | |
| Tags: | |
| Depends on: | |
| Blocks: | |
| See also: |
Robert Oostenveld - 2012-09-02 12:19:01 +0200
At the Biomag I discussed with one of the BESA developers how they deal with supporting users that have problems, how the users report them to the support staff, and how the problems are reproduced. One of the things they do is to ask the user to switch on "logging" in the preferences, then have the user go through all steps again to reproduce the problem. In the background a log file is written, which after the crash/error/problem can then be mailed by the user to the support staff. We could consider something similar. Imagine cfg.logfile="problem.txt" (to be set in ft_defaults to empty) and then implement an ft_preamble_logfile, ft_preamble_debug or integrate it into the other preambles. The logging could include details on the input cfg and input data. In the most elaborate form you could imagine saving the input cfg and data to a mat file, and deleting it at the end of the FT function. In case there is a FT function crash, the user could collect the mat file and share it with us. Less extreme options are printing some info on the input data and cfg to the ascii logfile, such that we can try to reproduce it. We can also think of using "diary". Or some try-catch instructions that inform the user to send a specific file to fieldtrip-support@donders. To be discussed at the FT meeting.
Robert Oostenveld - 2012-09-02 12:20:15 +0200
... "FIeldTrip has detected a problem, do you want it to send the information to the developers?" ...
Eelke Spaak - 2012-09-03 12:20:22 +0200
This sounds like a very good idea. In other languages, logging is usually implemented by having several log levels (e.g. debug, notice, warning, error) and then the user can specify a logger output and a desired logging level, e.g. in setup pseudocode: % record all logging statements to a mat-file ft_addlogoutput('debug', 'matfilelogger', 'mylog.mat'); % record only important stuff to a txt-file ft_addlogoutput('warning', 'textfilelogger', 'warningsAndErrors.txt'); Then our code can (and should) be interspersed with logging statements: ft_log('debug', 'inverting the mixing matrix'); ft_log('notice', 'matrix not singular, using pinv instead'); % or whatever that travel on to an output channel only if the specified logging level has been hooked up to a log destination.
Robert Oostenveld - 2012-09-13 12:19:07 +0200
This should be integrated with the cfg.showcallinfo handling in the ft_defaults script. Also to consider is logging to screen and file simultaneous.
Robert Oostenveld - 2012-09-14 12:38:03 +0200
*** Bug 1711 has been marked as a duplicate of this bug. ***
Robert Oostenveld - 2012-12-10 19:36:53 +0100
Should we consider making a special cfg flag like cfg.debug? E.g. ft_default.debug.saveinput = 'yes' cfg = []; cfg.option = ... dataout = ft_something(cfg, datain) which then writes the cfg, datain and the name of the function to a mat file? The ft_default fields are already automatically added to the cfg, so that is easy. The output file could be a temporary one, or specified by the user as fileprefix. My idea of the mat file is that it would contain funname = @ft_something argin = {cfg, datain} such that we could always do feval(funname, argin{:}) after loading the mat file. For generating better SPM test scripts, this would then involve setting cfg.debug.saveinput to yes, clicking around in the SPM gui for some time where all ft functions would save their inputs, and then gathering the mat files with those inputs. We could do the same at the donders to collect test data. Note that this would only affect the ft-main functions, not the low-level functions.
Vladimir Litvak - 2012-12-10 19:57:31 +0100
Not sure how useful this would be in the case of SPM as it rarely calls high-level functions
Robert Oostenveld - 2012-12-10 23:03:43 +0100
I made a pre and postable for high-level functions and added it to (sofar only) ft_timelockanalysis. It works by specifying cfg.debug = 'no' cfg.debug = 'displayonerror' cfg.debug = 'display' cfg.debug = 'saveonerror' cfg.debug = 'save' which displays or saves the input to the function (usually the cfg and the input data). The output file is auto-generated in the tmp directory with the function name, date and time in the filename. What remains to be done is to check how this works when different ft functions call each other. At the moment it is only guaranteed to work for a single call. mbp> svn commit utilities/ft_p* utilities/private/ft_p*debug.m ft_timelockanalysis.m ft_defaults.m Sending ft_defaults.m Sending ft_timelockanalysis.m Sending utilities/ft_postamble.m Sending utilities/ft_preamble.m Adding utilities/private/ft_postamble_debug.m Adding utilities/private/ft_preamble_debug.m Transmitting file data ...... Committed revision 7134.
Robert Oostenveld - 2012-12-19 08:47:03 +0100
(In reply to comment #7) I should also add the option saveonsuccess. That would allow to harvest known working input data and cfgs at the dccn.
Robert Oostenveld - 2014-07-19 10:27:49 +0200
I noticed that cfg.debug=saveonerror was not working. This turned out to be due to the "assign" anonymous function in ft_preamble_loadvar. mac011> svn commit utilities/ Sending utilities/private/ft_postamble_debug.m Sending utilities/private/ft_preamble_debug.m Sending utilities/private/ft_preamble_loadvar.m Transmitting file data ... Committed revision 9745.
Robert Oostenveld - 2014-07-19 10:37:58 +0200
(In reply to Robert Oostenveld from comment #9) I did some additional cleanups to the workspace, removing temporary variables as soon as possible. mac011> svn commit Sending private/ft_postamble_provenance.m Sending private/ft_preamble_debug.m Sending private/ft_preamble_provenance.m Transmitting file data ... Committed revision 9746.
Robert Oostenveld - 2014-07-19 11:07:55 +0200
I wrote this FAQ, which (together with the code) I consider enough for now. http://fieldtrip.fcdonders.nl/faq/how_can_i_debug_my_analysis_script_if_a_fieldtrip_function_gives_an_error We could in principle take a more active role in explaining this to more users.