4
$\begingroup$

I have an application that does a bunch of small computations, mostly Table management, and logic around loops. It takes seconds to execute. However, when I turn on debug (a variable I set for varying levels of output), which is often necessary to see how certain decisions were made, it can take 5 minutes to 15 minutes to execute. This is less than ideal, as I'm using this to aid live events in realtime.

Here, the debug function executed 9625 times in a recent execution. The function is as follows:

showDebug[debug_,thisDebug_,content_]:=
Module[{},
    howManyDebugs++;
    If[debug >= thisDebug,
        Print[content];
    ]
];

Content can consist of a simple one-line output or a stringified table.


Per answer below, I've upgraded the code to use

showDebug[debug_,thisDebug_,content_]:=
Module[{},
    howManyDebugs++;
    If[debug >= thisDebug,
        WriteString["stdout",content,"\n"];
    ]
];

Is there a more efficient way to capture this data than outputting to the screen?

After making the change detailed above, I've experienced a roughly 50% decrease in execution time.

$\endgroup$
  • 2
    $\begingroup$ This is hard to answer without knowing how you implemented debugging. Can you explain how you are doing it precisely, and what functions you are using to print the information? $\endgroup$ – Szabolcs Nov 9 '14 at 4:50
  • $\begingroup$ thanks for the quick reply. Pretty basic, I just have If[debug>value,Print["stuff"<>vars]]; $\endgroup$ – Rick R Nov 9 '14 at 5:36
  • $\begingroup$ Can you come up with a minimal working example to reproduce your problem? $\endgroup$ – Yves Klett Nov 9 '14 at 6:59
  • $\begingroup$ Check Sow and Reap. $\endgroup$ – Hector Nov 9 '14 at 9:10
10
$\begingroup$

You have several possibilities:

1) Instead of Printing into usual StandardForm Cell where the parsing and 2D formatting take significant processor's time you can print into plain text Cells:

CellPrint[Cell["stuff=" <> ToString[stuff]]]]

This takes substantially less CPU time and should render much faster.

2) Instead of printing into separate cells you can append the debug output into the same plain text Cell as described here:

stuff := RandomReal[];
Do[WriteString["stdout", "stuff=" <> ToString[stuff], "\n"], {10}]

This probably will render even faster.

3) Instead of printing hundreds of debug messages into Notebook try to use the Dynamic functionality for displaying necessary information.

4) Another possibility is to accumulate the debug information only in the Kernel, and implement a browser-like interface (example) for browsing the history of the dubug messages. This method allows to avoid rendering at the evaluation time completely.

5) Instead of printing into Notebook you can append your debugging information into a running log file using PutAppend. If you want to turn off the line wrapping in the running log file, execute the following:

SetOptions[OpenAppend, PageWidth -> Infinity]

6) Instead of PutAppend which opens and closes the file at every call you can use OpenAppend directly (or OpenWrite): open the running log file on the beginning, then Write the debug information to it, then Close the stream.

$\endgroup$
  • $\begingroup$ awesome, thank you very much, I will look into putting these in place, and report back on time increases. $\endgroup$ – Rick R Nov 10 '14 at 1:17
  • $\begingroup$ No output: 1.93s $\endgroup$ – Rick R Nov 10 '14 at 6:01
  • 1
    $\begingroup$ With no output, 1.9s to execute. Using Print["stuff"] as I was, 370s. Using WriteString["stdout","stuff","\n"] this was reduced to 166s. Pretty solid improvement. I'll check into the others as well. $\endgroup$ – Rick R Nov 10 '14 at 6:20
  • $\begingroup$ Applying option one (CelPrint), it slowed down to 850s. $\endgroup$ – Rick R Nov 10 '14 at 6:53
  • $\begingroup$ Have you tried the PutAppend method? I also have added the suggestion to use OpenAppend or OpenWrite directly. $\endgroup$ – Alexey Popkov Nov 10 '14 at 13:23
0
$\begingroup$

Using your improved code with WriteString I find that printing 25,000 lines is essentially instantaneous on my system, therefore I doubt that this function itself is the problem. How is it being called? What does the code surrounding it look like?

It may be that your debug function is preventing some part of your code from automatically compiling. If that is the case only a compilable method is likely to be close to as fast as your code without the debug function. However I think you will not be able to compile a function that prints in real time so I will not pursue this; I only mention it as a possible explanation for your performance issue.

$\endgroup$
  • $\begingroup$ The code surrounding it varies a fair amount. In general I have a bunch of nested For loops and If-based flow control to represent different portions of game logic, and the debugs output current state: impacts, changes, location, etc. I've since learned that For loops are not the way to approach problems in Mathematica, but the changes are slow going. $\endgroup$ – Rick R Nov 10 '14 at 17:41

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.