View mode: basic / threaded / horizontal-split · Log in · Help
February 24, 2013
[Issue 9581] New: Regression (2.053): Exception takes too much time to show up
http://d.puremagic.com/issues/show_bug.cgi?id=9581

          Summary: Regression (2.053): Exception takes too much time to
                   show up
          Product: D
          Version: D2
         Platform: All
       OS/Version: Windows
           Status: NEW
         Keywords: EH, performance
         Severity: regression
         Priority: P2
        Component: DMD
       AssignedTo: nobody@puremagic.com
       ReportedBy: andrej.mitrovich@gmail.com


--- Comment #0 from Andrej Mitrovic <andrej.mitrovich@gmail.com> 2013-02-23 18:35:50 PST ---
test.d:

------
module test;

void main()
{
   assert(0);
}
------

timer.d (or use your favorite timer app):

------
module timer;

import std.stdio;
import std.process;
import std.datetime;

void main()
{
   auto sw1 = StopWatch(AutoStart.yes);

   system("dmd test.d");
   system("test");

   sw1.stop();
   writefln("%s msecs.", sw1.peek.msecs);
}
------

DMD 2.052:
$ dmd timer.d
$ timer
> 81 msecs.

DMD 2.053:
$ dmd timer.d
$ timer
> 4127 msecs.

This is using XP SP3.

-- 
Configure issuemail: http://d.puremagic.com/issues/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
February 24, 2013
[Issue 9581] Regression (2.053): Exception takes too much time to show up
http://d.puremagic.com/issues/show_bug.cgi?id=9581



--- Comment #1 from Andrej Mitrovic <andrej.mitrovich@gmail.com> 2013-02-23 18:36:24 PST ---
And this can be recreated all the way up to 2.062 and 2.063 git-head.

-- 
Configure issuemail: http://d.puremagic.com/issues/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
February 24, 2013
[Issue 9581] Regression (2.053): Exception takes too much time to show up
http://d.puremagic.com/issues/show_bug.cgi?id=9581


Steven Schveighoffer <schveiguy@yahoo.com> changed:

          What    |Removed                     |Added
----------------------------------------------------------------------------
                CC|                            |schveiguy@yahoo.com


--- Comment #2 from Steven Schveighoffer <schveiguy@yahoo.com> 2013-02-23 19:24:45 PST ---
Doesn't this just test the compile time?  Not that 4 second compile time is
really acceptable, but I don't know if this test does what you think it does.

What happens when you remove the compilation line?

-- 
Configure issuemail: http://d.puremagic.com/issues/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
February 24, 2013
[Issue 9581] Regression (2.053): Exception takes too much time to show up
http://d.puremagic.com/issues/show_bug.cgi?id=9581



--- Comment #3 from Andrej Mitrovic <andrej.mitrovich@gmail.com> 2013-02-23 19:27:56 PST ---
(In reply to comment #2)
> Doesn't this just test the compile time?  Not that 4 second compile time is
> really acceptable, but I don't know if this test does what you think it does.
> 
> What happens when you remove the compilation line?

Sorry about that, it was a misplaced system call.

Without timing the compilation its faster but still 4050 msecs. Here's the
newer script:

timer.d:
---------
module timer;

import std.stdio;
import std.process;
import std.datetime;

void main()
{
   system("dmd test.d");

   auto sw1 = StopWatch(AutoStart.yes);

   system("test");

   sw1.stop();
   writefln("%s msecs.", sw1.peek.msecs);
}
---------

-- 
Configure issuemail: http://d.puremagic.com/issues/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
February 24, 2013
[Issue 9581] Regression (2.053): Exception takes too much time to show up
http://d.puremagic.com/issues/show_bug.cgi?id=9581


Jonathan M Davis <jmdavisProg@gmx.com> changed:

          What    |Removed                     |Added
----------------------------------------------------------------------------
                CC|                            |jmdavisProg@gmx.com


--- Comment #4 from Jonathan M Davis <jmdavisProg@gmx.com> 2013-02-23 19:40:28 PST ---
If what you're testing is the amount of time that it takes an exception to be
thrown and caught, then you shouldn't be doing anything like call system, since
then that's testing what system's up to. And even worse, you're starting a
different program, meaning that you're testing the amount of time it takes to
run the program (including the startup time for druntime). Please test only one
thing at a time.

If system's too slow, then create a test just for that and a bug report for it.
If exceptions are too slow, then cerate a test just for that and bug report for
it. If druntime takes too long to startup, then create a test just for that and
create a bug report for it. You're testing too many things at once here.

-- 
Configure issuemail: http://d.puremagic.com/issues/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
February 24, 2013
[Issue 9581] Regression (2.053): Exception takes too much time to show up
http://d.puremagic.com/issues/show_bug.cgi?id=9581



--- Comment #5 from Andrej Mitrovic <andrej.mitrovich@gmail.com> 2013-02-23 19:47:32 PST ---
(In reply to comment #4)
> If what you're testing is the amount of time that it takes an exception to be
> thrown and caught, then you shouldn't be doing anything like call system, since
> then that's testing what system's up to. And even worse, you're starting a
> different program, meaning that you're testing the amount of time it takes to
> run the program (including the startup time for druntime). Please test only one
> thing at a time.
> 
> If system's too slow, then create a test just for that and a bug report for it.
> If exceptions are too slow, then cerate a test just for that and bug report for
> it. If druntime takes too long to startup, then create a test just for that and
> create a bug report for it. You're testing too many things at once here.

This is the test-case:

--------
module test;

void main()
{
   assert(0);
}
---------

You can use `timeit` or some other timing app you may have installed on the
system, the 'timer' was just there in case someone doesn't have an alternative
to test it with. 

Anyway you can get 'timeit' from
http://www.microsoft.com/en-us/download/details.aspx?id=17657, then the test
runs are:

2.052:
$ D:\foobar>dmd test.d
$ D:\foobar>timeit test
core.exception.AssertError@test(5): Assertion failure

Version Number:   Windows NT 5.1 (Build 2600)
Exit Time:        4:45 am, Sunday, February 24 2013
Elapsed Time:     0:00:00.078
Process Time:     0:00:00.031
System Calls:     2121
Context Switches: 456
Page Faults:      678
Bytes Read:       142408
Bytes Written:    0
Bytes Other:      124382

2.053:
D:\foobar>dmd test.d
D:\foobar>timeit test
core.exception.AssertError@test(5): Assertion failure
----------------
40CE70
40CCE7
40201A
4025C7
4021C3
4120C9
7C817067
----------------

Version Number:   Windows NT 5.1 (Build 2600)
Exit Time:        4:46 am, Sunday, February 24 2013
Elapsed Time:     0:00:04.093
Process Time:     0:00:01.265
System Calls:     72733
Context Switches: 38975
Page Faults:      18821
Bytes Read:       17758445
Bytes Written:    8283
Bytes Other:      55317

The system calls should give a hint here, it's an enormous increase from 2121
calls in 2.052 to 72733 calls in 2.053.

-- 
Configure issuemail: http://d.puremagic.com/issues/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
February 24, 2013
[Issue 9581] Regression (2.053): Exception takes too much time to show up
http://d.puremagic.com/issues/show_bug.cgi?id=9581



--- Comment #6 from Steven Schveighoffer <schveiguy@yahoo.com> 2013-02-23 20:09:28 PST ---
Also note, the new version prints a stack trace, while the previous doesn't. 
Interesting.  I wonder if that is what is taking so long.

-- 
Configure issuemail: http://d.puremagic.com/issues/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
February 24, 2013
[Issue 9581] Regression (2.053): Exception takes too much time to show up
http://d.puremagic.com/issues/show_bug.cgi?id=9581



--- Comment #7 from Andrej Mitrovic <andrej.mitrovich@gmail.com> 2013-02-23 20:14:06 PST ---
(In reply to comment #6)
> Also note, the new version prints a stack trace, while the previous doesn't. 
> Interesting.  I wonder if that is what is taking so long.

Yeah. Considering how long it takes I really wonder if we can improve the speed
in some way. E.g. we could provide a switch to disable the stack-trace.

Or maybe the real issue is spending time finding dbghelp.dll. If that's the
case, we could try to search for a specific environment variable that the user
would set so the DLL is quickly found. Anyway that's only guessing that's the
actual issue.

-- 
Configure issuemail: http://d.puremagic.com/issues/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
February 24, 2013
[Issue 9581] Regression (2.053): Exception takes too much time to show up
http://d.puremagic.com/issues/show_bug.cgi?id=9581



--- Comment #8 from Jonathan M Davis <jmdavisProg@gmx.com> 2013-02-23 20:50:30 PST ---
Exceptions in general are overly slow. As I understand it, one of the major
things that could be done would be to make it so that it doesn't actually
determine the strings for the stacktrace when it's constructed but rather when
toString is called on it. We currently incur that extra regardless of whether
the exception's toString method is ever used. Now, I don't think that it would
help any in this case, because the toString method _is_ being used, but it is
something that should be done to improve the performance of exceptions. And I'm
sure that there are plenty of other things that could be done as well, but I
don't know the inner workings of druntime well enough to know what they might
be. Java beats the pants of D in exception speed though.

-- 
Configure issuemail: http://d.puremagic.com/issues/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
February 24, 2013
[Issue 9581] Regression (2.053): Exception takes too much time to show up
http://d.puremagic.com/issues/show_bug.cgi?id=9581



--- Comment #9 from Steven Schveighoffer <schveiguy@yahoo.com> 2013-02-24 06:52:00 PST ---
(In reply to comment #8)
> Exceptions in general are overly slow.

Yeah, but not *4 seconds* slow, that is unacceptable.

-- 
Configure issuemail: http://d.puremagic.com/issues/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
« First   ‹ Prev
1 2 3
Top | Discussion index | About this forum | D home