Mercurial > hg > octave-nkf
view doc/interpreter/debug.txi @ 18552:02ce68d63fba stable rc-3-8-1-3
fix release date for 3.8.1 and bump release to 3.8.1-rc3
* configure.ac (OCTAVE_VERSION): Bump to 3.8.1-rc3.
(OCTAVE_MINOR_VERSION): Bump to 1-rc3.
(OCTAVE_RELEASE_DATE): Set to 2014-02-17.
author | John W. Eaton <jwe@octave.org> |
---|---|
date | Mon, 17 Feb 2014 03:30:17 -0500 |
parents | 7e39cbefe299 |
children | 446c46af4b42 |
line wrap: on
line source
@c Copyright (C) 1996-2013 John W. Eaton @c @c This file is part of Octave. @c @c Octave is free software; you can redistribute it and/or modify it @c under the terms of the GNU General Public License as published by the @c Free Software Foundation; either version 3 of the License, or (at @c your option) any later version. @c @c Octave is distributed in the hope that it will be useful, but WITHOUT @c ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or @c FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License @c for more details. @c @c You should have received a copy of the GNU General Public License @c along with Octave; see the file COPYING. If not, see @c <http://www.gnu.org/licenses/>. @node Debugging @chapter Debugging Octave includes a built-in debugger to aid in the development of scripts. This can be used to interrupt the execution of an Octave script at a certain point, or when certain conditions are met. Once execution has stopped, and debug mode is entered, the symbol table at the point where execution has stopped can be examined and modified to check for errors. The normal command-line editing and history functions are available in debug mode. @menu * Entering Debug Mode:: * Leaving Debug Mode:: * Breakpoints:: * Debug Mode:: * Call Stack:: * Profiling:: * Profiler Example:: @end menu @node Entering Debug Mode @section Entering Debug Mode There are two basic means of interrupting the execution of an Octave script. These are breakpoints (@pxref{Breakpoints}), discussed in the next section, and interruption based on some condition. Octave supports three means to stop execution based on the values set in the functions @code{debug_on_interrupt}, @code{debug_on_warning}, and @code{debug_on_error}. @DOCSTRING(debug_on_interrupt) @DOCSTRING(debug_on_warning) @DOCSTRING(debug_on_error) @node Leaving Debug Mode @section Leaving Debug Mode Use either @code{dbcont} or @code{return} to leave the debug mode and continue the normal execution of the script. @DOCSTRING(dbcont) To quit debug mode and return directly to the prompt without executing any additional code use @code{dbquit}. @DOCSTRING(dbquit) Finally, typing @code{exit} or @code{quit} at the debug prompt will result in Octave terminating normally. @node Breakpoints @section Breakpoints Breakpoints can be set in any m-file function by using the @code{dbstop} function. @DOCSTRING(dbstop) @noindent Breakpoints in class methods are also supported (e.g., @code{dbstop ("@@class/method")}). However, breakpoints cannot be set in built-in functions (e.g., @code{sin}, etc.) or dynamically loaded functions (i.e., oct-files). To set a breakpoint immediately upon entering a function use line number 1, or omit the line number entirely and just give the function name. When setting the breakpoint Octave will ignore the leading comment block, and the breakpoint will be set on the first executable statement in the function. For example: @example @group dbstop ("asind", 1) @result{} 29 @end group @end example @noindent Note that the return value of @code{29} means that the breakpoint was effectively set to line 29. The status of breakpoints in a function can be queried with @code{dbstatus}. @DOCSTRING(dbstatus) @noindent Reusing the previous example, @code{dbstatus ("asind")} will return 29. The breakpoints listed can then be cleared with the @code{dbclear} function. @DOCSTRING(dbclear) @noindent A breakpoint may also be set in a subfunction. For example, if a file contains the functions @example @group function y = func1 (x) y = func2 (x); endfunction function y = func2 (x) y = x + 1; endfunction @end group @end example @noindent then a breakpoint can be set at the start of the subfunction directly with @example @group dbstop (["func1", filemarker(), "func2"]) @result{} 5 @end group @end example Note that @code{filemarker} returns the character that marks subfunctions from the file containing them. Unless the default has been changed this character is @samp{>}. Thus, a quicker and more normal way to set the breakpoint would be @example dbstop func1>func2 @end example Another simple way of setting a breakpoint in an Octave script is the use of the @code{keyboard} function. @DOCSTRING(keyboard) @noindent The @code{keyboard} function is placed in a script at the point where the user desires that the execution be stopped. It automatically sets the running script into the debug mode. @node Debug Mode @section Debug Mode There are three additional support functions that allow the user to find out where in the execution of a script Octave entered the debug mode, and to print the code in the script surrounding the point where Octave entered debug mode. @DOCSTRING(dbwhere) @DOCSTRING(dbtype) @DOCSTRING(dblist) You may also use @code{isdebugmode} to determine whether the debugger is currently active. @DOCSTRING(isdebugmode) Debug mode also allows single line stepping through a function using the command @code{dbstep}. @DOCSTRING(dbstep) When in debug mode the @key{RETURN} key will execute the last entered command. This is useful, for example, after hitting a breakpoint and entering @code{dbstep} once. After that, one can advance line by line through the code with only a single key stroke. @node Call Stack @section Call Stack The function being debugged may be the leaf node of a series of function calls. After examining values in the current subroutine it may turn out that the problem occurred in earlier pieces of code. Use @code{dbup} and @code{dbdown} to move up and down through the series of function calls to locate where variables first took on the wrong values. @code{dbstack} shows the entire series of function calls and at what level debugging is currently taking place. @DOCSTRING(dbstack) @DOCSTRING(dbup) @DOCSTRING(dbdown) @node Profiling @section Profiling @cindex profiler @cindex code profiling Octave supports profiling of code execution on a per-function level. If profiling is enabled, each call to a function (supporting built-ins, operators, functions in oct- and mex-files, user-defined functions in Octave code and anonymous functions) is recorded while running Octave code. After that, this data can aid in analyzing the code behavior, and is in particular helpful for finding ``hot spots'' in the code which use up a lot of computation time and are the best targets to spend optimization efforts on. The main command for profiling is @code{profile}, which can be used to start or stop the profiler and also to query collected data afterwards. The data is returned in an Octave data structure which can then be examined or further processed by other routines or tools. @DOCSTRING(profile) An easy way to get an overview over the collected data is @code{profshow}. This function takes the profiler data returned by @code{profile} as input and prints a flat profile, for instance: @example @group Function Attr Time (s) Calls ---------------------------------------- >myfib R 2.195 13529 binary <= 0.061 13529 binary - 0.050 13528 binary + 0.026 6764 @end group @end example This shows that most of the run time was spent executing the function @samp{myfib}, and some minor proportion evaluating the listed binary operators. Furthermore, it is shown how often the function was called and the profiler also records that it is recursive. @DOCSTRING(profshow) @DOCSTRING(profexplore) @node Profiler Example @section Profiler Example Below, we will give a short example of a profiler session. @xref{Profiling}, for the documentation of the profiler functions in detail. Consider the code: @example global N A; N = 300; A = rand (N, N); function xt = timesteps (steps, x0, expM) global N; if (steps == 0) xt = NA (N, 0); else xt = NA (N, steps); x1 = expM * x0; xt(:, 1) = x1; xt(:, 2 : end) = timesteps (steps - 1, x1, expM); endif endfunction function foo () global N A; initial = @@(x) sin (x); x0 = (initial (linspace (0, 2 * pi, N)))'; expA = expm (A); xt = timesteps (100, x0, expA); endfunction function fib = bar (N) if (N <= 2) fib = 1; else fib = bar (N - 1) + bar (N - 2); endif endfunction @end example If we execute the two main functions, we get: @example @group tic; foo; toc; @result{} Elapsed time is 2.37338 seconds. tic; bar (20); toc; @result{} Elapsed time is 2.04952 seconds. @end group @end example But this does not give much information about where this time is spent; for instance, whether the single call to @code{expm} is more expensive or the recursive time-stepping itself. To get a more detailed picture, we can use the profiler. @example @group profile on; foo; profile off; data = profile ("info"); profshow (data, 10); @end group @end example This prints a table like: @example @group # Function Attr Time (s) Calls --------------------------------------------- 7 expm 1.034 1 3 binary * 0.823 117 41 binary \ 0.188 1 38 binary ^ 0.126 2 43 timesteps R 0.111 101 44 NA 0.029 101 39 binary + 0.024 8 34 norm 0.011 1 40 binary - 0.004 101 33 balance 0.003 1 @end group @end example The entries are the individual functions which have been executed (only the 10 most important ones), together with some information for each of them. The entries like @samp{binary *} denote operators, while other entries are ordinary functions. They include both built-ins like @code{expm} and our own routines (for instance @code{timesteps}). From this profile, we can immediately deduce that @code{expm} uses up the largest proportion of the processing time, even though it is only called once. The second expensive operation is the matrix-vector product in the routine @code{timesteps}. @footnote{We only know it is the binary multiplication operator, but fortunately this operator appears only at one place in the code and thus we know which occurrence takes so much time. If there were multiple places, we would have to use the hierarchical profile to find out the exact place which uses up the time which is not covered in this example.} Timing, however, is not the only information available from the profile. The attribute column shows us that @code{timesteps} calls itself recursively. This may not be that remarkable in this example (since it's clear anyway), but could be helpful in a more complex setting. As to the question of why is there a @samp{binary \} in the output, we can easily shed some light on that too. Note that @code{data} is a structure array (@ref{Structure Arrays}) which contains the field @code{FunctionTable}. This stores the raw data for the profile shown. The number in the first column of the table gives the index under which the shown function can be found there. Looking up @code{data.FunctionTable(41)} gives: @example @group scalar structure containing the fields: FunctionName = binary \ TotalTime = 0.18765 NumCalls = 1 IsRecursive = 0 Parents = 7 Children = [](1x0) @end group @end example Here we see the information from the table again, but have additional fields @code{Parents} and @code{Children}. Those are both arrays, which contain the indices of functions which have directly called the function in question (which is entry 7, @code{expm}, in this case) or been called by it (no functions). Hence, the backslash operator has been used internally by @code{expm}. Now let's take a look at @code{bar}. For this, we start a fresh profiling session (@code{profile on} does this; the old data is removed before the profiler is restarted): @example @group profile on; bar (20); profile off; profshow (profile ("info")); @end group @end example This gives: @example @group # Function Attr Time (s) Calls ------------------------------------------------------- 1 bar R 2.091 13529 2 binary <= 0.062 13529 3 binary - 0.042 13528 4 binary + 0.023 6764 5 profile 0.000 1 8 false 0.000 1 6 nargin 0.000 1 7 binary != 0.000 1 9 __profiler_enable__ 0.000 1 @end group @end example Unsurprisingly, @code{bar} is also recursive. It has been called 13,529 times in the course of recursively calculating the Fibonacci number in a suboptimal way, and most of the time was spent in @code{bar} itself. Finally, let's say we want to profile the execution of both @code{foo} and @code{bar} together. Since we already have the run-time data collected for @code{bar}, we can restart the profiler without clearing the existing data and collect the missing statistics about @code{foo}. This is done by: @example @group profile resume; foo; profile off; profshow (profile ("info"), 10); @end group @end example As you can see in the table below, now we have both profiles mixed together. @example @group # Function Attr Time (s) Calls --------------------------------------------- 1 bar R 2.091 13529 16 expm 1.122 1 12 binary * 0.798 117 46 binary \ 0.185 1 45 binary ^ 0.124 2 48 timesteps R 0.115 101 2 binary <= 0.062 13529 3 binary - 0.045 13629 4 binary + 0.041 6772 49 NA 0.036 101 @end group @end example