On Mon, 23 Aug 2010 14:11:52 -0400, Walter Bright <newshou...@digitalmars.com> wrote:

Steven Schveighoffer wrote:
On Mon, 23 Aug 2010 13:41:07 -0400, Walter Bright <newshou...@digitalmars.com> wrote:

Steven Schveighoffer wrote:
I get a long list of functions proceeding at a reasonable rate. I've done that in the past, I feel it's some sort of inner loop problem. Essentially, something takes way longer to compile than it should, but way longer on the order of .05 seconds instead of .005 seconds, so you don't notice it normally. But somehow my library is able to harness that deficiency and multiply by 1000. I don't know, it doesn't seem like dcollections should evoke such a long compile time.

with or without -O ?
 The compile line is:
 dmd -unittest unit_test.d dcollections/*.d dcollections/model/*.d
 Where unit_test.d is a dummy main.

You could try running dmd under a profiler, then.

I recompiled dmd 2.047 with -pg added and with the COV options uncommented out (not sure what all is needed)

I then tried running my build script, and it took about 5 minutes for me to give up :)

So I reduced the build line to build just what is necessary to build a hash map.

The compile line looks like this:

dmd -unittest unit_test.d dcollections/HashMap.d dcollections/Hash.d dcollections/Iterators.d dcollections/model/*

I don't think model/* is really needed, but I don't suspect there is too much code in there to compile, it's all interfaces, no unit tests.

So without profiling, the compiler takes 4 seconds to compile this one file with unit tests.

With profiling enabled, gprof outputs this as the top hitters:


Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
77.76 6.68 6.68 2952 2.26 2.26 elf_findstr(Outbuffer*, char const*, char const*)
  2.10      6.86     0.18     4342     0.04     0.04  searchfixlist
1.28 6.97 0.11 663755 0.00 0.00 ScopeDsymbol::search(Loc, Identifier*, int)
  1.05      7.06     0.09  2623497     0.00     0.00  isType(Object*)
0.76 7.12 0.07 911667 0.00 0.00 match(Object*, Object*, TemplateDeclaration*, Scope*) 0.76 7.19 0.07 656268 0.00 0.00 _aaGetRvalue(AA*, void*)
  0.58      7.24     0.05  2507041     0.00     0.00  isTuple(Object*)
  0.52      7.29     0.04  2548939     0.00     0.00  isExpression(Object*)
0.47 7.33 0.04 10124 0.00 0.01 ClassDeclaration::search(Loc, Identifier*, int) 0.35 7.36 0.03 136688 0.00 0.00 StringTable::search(char const*, unsigned int) 0.35 7.38 0.03 122998 0.00 0.00 Scope::search(Loc, Identifier*, Dsymbol**) 0.35 7.42 0.03 79912 0.00 0.00 Parameter::dim(Parameters*) 0.35 7.45 0.03 43500 0.00 0.00 AliasDeclaration::semantic(Scope*) 0.35 7.47 0.03 26358 0.00 0.01 TemplateInstance::semantic(Scope*, Expressions*)
  0.29      7.50     0.03  2537875     0.00     0.00  isDsymbol(Object*)
  0.23      7.52     0.02  4974808     0.00     0.00  Tuple::dyncast()
  0.23      7.54     0.02  4843755     0.00     0.00  Type::dyncast()
0.23 7.56 0.02 1243524 0.00 0.00 operator new(unsigned int) 0.23 7.58 0.02 904514 0.00 0.00 arrayObjectMatch(Objects*, Objects*, TemplateDeclaration*, Scope*) 0.23 7.60 0.02 365820 0.00 0.00 speller_test(void*, char const*) 0.23 7.62 0.02 285816 0.00 0.00 Array::reserve(unsigned int)
  0.23      7.64     0.02   271143     0.00     0.00  calccodsize
0.23 7.66 0.02 149682 0.00 0.00 Dchar::calcHash(char const*, unsigned int)
  0.23      7.68     0.02    73379     0.00     0.00  TypeBasic::size(Loc)
0.23 7.70 0.02 39394 0.00 0.00 DsymbolExp::semantic(Scope*) 0.23 7.72 0.02 20885 0.00 0.00 TemplateInstance::semanticTiargs(Loc, Scope*, Objects*, int) 0.23 7.74 0.02 11877 0.00 0.00 TemplateDeclaration::deduceFunctionTemplateMatch(Scope*, Loc, Objects*, Expression*, Expressions*, Objects*)
  0.23      7.76     0.02     5442     0.00     0.01  optelem(elem*, int)
0.23 7.78 0.02 __i686.get_pc_thunk.bx
  0.12      7.79     0.01  1458990     0.00     0.00  Object::Object()
0.12 7.80 0.01 656266 0.00 0.00 DsymbolTable::lookup(Identifier*) 0.12 7.81 0.01 462797 0.00 0.00 Module::search(Loc, Identifier*, int) 0.12 7.82 0.01 414377 0.00 0.00 Dsymbol::isTemplateInstance() 0.12 7.83 0.01 354954 0.00 0.00 Expression::Expression(Loc, TOK, int)
  0.12      7.84     0.01   354693     0.00     0.00  Dsymbol::pastMixin()
0.12 7.85 0.01 167119 0.00 0.00 Dsymbol::checkDeprecated(Loc, Scope*)
  0.12      7.86     0.01   151694     0.00     0.00  Type::merge()
  0.12      7.87     0.01   123694     0.00     0.00  Lstring::toDchars()
  0.12      7.88     0.01   111982     0.00     0.00  el_calloc()
0.12 7.89 0.01 111569 0.00 0.00 resolveProperties(Scope*, Expression*)
  0.12      7.90     0.01   107359     0.00     0.00  code_calloc
  0.12      7.91     0.01   106932     0.00     0.00  Lexer::peek(Token*)
  0.12      7.92     0.01   106468     0.00     0.00  Scope::pop()
  0.12      7.93     0.01    99136     0.00     0.00  Array::push(void*)
...

I can add more, but I have no idea what part of this is important for diagnosing the problem. From a naive look, it appears that elf_findstr is the problem (only 3k calls, but uses almost 80% of the runtime?), but I have no idea how to interpret this, and I don't know what the compiler does.

The compiler ended up eventually not producing an exe with the message "cannot find ld", but I don't think the link step is where the problem is anyways.

If you need more data, or want me to run something else, I can.

-Steve

Reply via email to