7
$\begingroup$

Issuing messages takes a very long time in version 9 and version 10. Can others reproduce this? Is there a fix?

Update: This is slow only when using the front end, but not when running the kernel from a terminal. System-messages tend to be faster, but not nearly as fast as they were in v8. (Message[General::args, "boo"] // AbsoluteTiming)

Version 8

Version 8 is fast. The second invocation of Message is much faster.

In[1]:= $Version    
Out[1]= "8.0 for Mac OS X x86 (64-bit) (July 22, 2012)"

In[2]:= mysym::mess = "message";

In[3]:= Message[mysym::mess] // AbsoluteTiming

During evaluation of In[3]:= mysym::mess: message

Out[3]= {0.110727, Null}

In[4]:= Message[mysym::mess] // AbsoluteTiming

During evaluation of In[4]:= mysym::mess: message

Out[4]= {0.000389, Null}

Version 9

Version 9 is slow

In[1]:= $Version    
Out[1]= "9.0 for Mac OS X x86 (64-bit) (January 24, 2013)"

In[2]:= mysym::mess = "message";

In[3]:= Message[mysym::mess] // AbsoluteTiming

During evaluation of In[3]:= mysym::mess: message

Out[3]= {0.364160, Null}

In[4]:= Message[mysym::mess] // AbsoluteTiming

During evaluation of In[4]:= mysym::mess: message

Out[4]= {0.220693, Null}

Version 10

Version 10 is slow just like version 9:

In[1]:= $Version    
Out[1]= "10.0 for Mac OS X x86 (64-bit) (June 29, 2014)"

In[2]:= mysym::mess = "message";

In[3]:= Message[mysym::mess] // AbsoluteTiming

During evaluation of In[3]:= mysym::mess: message

Out[3]= {0.343261, Null}

In[4]:= Message[mysym::mess] // AbsoluteTiming

During evaluation of In[4]:= mysym::mess: message

Out[4]= {0.271947, Null}
|improve this question
$\endgroup$
  • $\begingroup$ I have very similar timings under V8 and V10 (did not check V9 now) under Linux $\endgroup$ – sebhofer Jul 16 '14 at 22:28
  • $\begingroup$ @sebhofer With front end or in a terminal? Or those timings less than 0.1 second? $\endgroup$ – Szabolcs Jul 16 '14 at 22:34
  • $\begingroup$ Front end. They are basically what you have in both cases. $\endgroup$ – sebhofer Jul 16 '14 at 22:36
  • 1
    $\begingroup$ I'm curious. Why is this speed relevant? I never get more than a few messages, and then they just don't show because they are repeated, or I start trying to abort. $\endgroup$ – Rojo Jul 17 '14 at 1:19
1
$\begingroup$

This is not an answer, merely some observations I've made in the past.

data1 = Reap[TraceScan[Sow, 1/0, TraceInternal -> True]][[-1, 1]];
Length[data1]

(* 182126 *)

data2 = Reap[TraceScan[Sow, Quiet[1/0], TraceInternal -> True]][[-1, 1]];
Length[data2]

(* 39 *)

So we see about 4670 times many function calls are made when a message is generated. I only glanced through data1, but it appears the extra calls deal with stuff like documentation retrieval, etc (as one would expect).

The timing difference seems to be on the same order of magnitude as the number of function calls above:

First[AbsoluteTiming[1/0]]/First[AbsoluteTiming[Quiet[1/0]]]

(* 6.*10^3 *)
|improve this answer
$\endgroup$

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.