Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Extremely slow performance when running in directory with lots of modules #5711

Closed
p6rt opened this issue Oct 1, 2016 · 9 comments
Closed

Extremely slow performance when running in directory with lots of modules #5711

p6rt opened this issue Oct 1, 2016 · 9 comments

Comments

@p6rt
Copy link

@p6rt p6rt commented Oct 1, 2016

Migrated from rt.perl.org#129776 (status was 'resolved')

Searchable as RT129776$

@p6rt
Copy link
Author

@p6rt p6rt commented Oct 1, 2016

From @zoffixznet

To reproduce​:

  cd $(mktemp -d); git clone https://github.com/perl6/mu; touch Foo.pm6;
  perl6 -I. -MFoo -e ''

The perl6 command will appear to hang, although it will finish after a
long time.

The problem is due to repo ID being calculated [^1] by slurping ALL of
the .pm6? files in the directory and subdirectories,
concatenating all that date, and calculating sha for it.

To fix the issue, and different method of coming up with the repo ID
needs to be used.

[1]
https://github.com/rakudo/rakudo/blob/nom/src/core/CompUnit/Repository/FileSystem.pm#L63

@p6rt
Copy link
Author

@p6rt p6rt commented Oct 2, 2016

From @LLFourn

String concat takes On2 in rakudo I think. Using join in this kind of
situation should be an improvement. (I'm commuting so can't test).
On Sat, 1 Oct 2016 at 7​:11 PM, Zoffix Znet <perl6-bugs-followup@​perl.org>
wrote​:

# New Ticket Created by Zoffix Znet
# Please include the string​: [perl #​129776]
# in the subject line of all future correspondence about this issue.
# <URL​: https://rt-archive.perl.org/perl6/Ticket/Display.html?id=129776 >

To reproduce​:

 cd $\(mktemp \-d\); git clone https://github.com/perl6/mu; touch

Foo.pm6;
perl6 -I. -MFoo -e ''

The perl6 command will appear to hang, although it will finish after a
long time.

The problem is due to repo ID being calculated [^1] by slurping ALL of
the .pm6? files in the directory and subdirectories,
concatenating all that date, and calculating sha for it.

To fix the issue, and different method of coming up with the repo ID
needs to be used.

[1]

https://github.com/rakudo/rakudo/blob/nom/src/core/CompUnit/Repository/FileSystem.pm#L63

@p6rt
Copy link
Author

@p6rt p6rt commented Oct 2, 2016

The RT System itself - Status changed from 'new' to 'open'

@p6rt
Copy link
Author

@p6rt p6rt commented Oct 2, 2016

From @timo

On 02/10/16 04​:41, Lloyd Fournier wrote​:

String concat takes On2 in rakudo I think. Using join in this kind of
situation should be an improvement. (I'm commuting so can't test).

MoarVM implements "ropes" which make the performance a whole lot better.
join can still be a small improvement, but not as much as it would if
string concat was actually O(n^2).

@p6rt
Copy link
Author

@p6rt p6rt commented Oct 2, 2016

From @timo

Here's the results from a --profile-compile​:

1. match (gen/moar/m-CORE.setting​:12064), 12750 entries, 25.66%
inclusive time, 8.15% exclusive time
2. <anon> (gen/moar/m-BOOTSTRAP.nqp​:2081), 111530 entries, 4.59%
inclusive time, 4.36% exclusive time
3. <anon> (gen/moar/m-CORE.setting​:40776), 13148 entries, 6.85%
inclusive, 4.16% exclusive time
4. canonpath (gen/moar/m-CORE.setting​:27919), 25500 entries, 40%
inclusive time, 3.12% exclusive time
5. <anon> (gen/moar/m-CORE.setting​:27924), 25501 entries, 2.99%
inclusive time, 2.9% exclusive time
6. FILETEST-D (gen/moar/m-CORE.setting​:3909), 68721 entries, 2.73%
inclusive time, 2.73% exclusive time
7. STORE (gen/moar/m-CORE.setting​:16678), 204002 entries, 8.21%
inclusive time, 2.42% exclusive time

I think the fourth spot, "canonpath" taking 40% inclusive time, is
what's messing us up here. If we could avoid running it as often, we
could get significant savings.

@p6rt
Copy link
Author

@p6rt p6rt commented Oct 2, 2016

From @timo

Sorry, I was running the profile on a 4-weeks-old rakudo. After the
optimizations i did to canonpath ~22 days ago the canonpath inclusive
time went down to about 18% ...

FILETEST-D and FILETEST-F are in spots 3 and 4, but they only take 3594
/ 26881 msec and 2749 / 216298 msec per invocation, so they are just
called really, really often.

next up is the loop from dir(), the one inside the gather. it sits at
10.44% inclusive time and 3.16% exclusive time.

dir itself takes 17.8% inclusive time and 3.12% exclusive time, which
seems to suggest it has a bit of overhead i'm not quite sure where to find.

match is up next at about 8.8% inclusive and 2.91% exclusive. I'm not
sure where exactly regex matches happen here; maybe a part of it comes
from canonpath.

AUTOTHREAD is at 12% inclusive time, which i find interesting. Perhaps
the reason is the test for dir, which by default is a none-junction.
Perhaps we can just use a little closure instead that eq's against . and
.. instead of going through a somewhat-more-expensive junction autothread.

That's all my thoughts for now.

@p6rt
Copy link
Author

@p6rt p6rt commented Oct 6, 2016

From @lizmat

By re-implementing Rakudo​::Internals.DIR-RECURSE, the time has gone down to about a second. This is still calculating a SHA1 of ~1000 files for the perl6/mu case, but the overhead of scanning the directories is now much less because directory entries are pruned much earlier, and directories like .git are now skipped (they weren’t before). And there also some junctions in there that weren’t strictly necessary. Also dir() got a bit faster in the process as well (although DIR-RECURSE now no longer uses dir()).

On 02 Oct 2016, at 20​:10, Timo Paulssen <timo@​wakelift.de> wrote​:

Sorry, I was running the profile on a 4-weeks-old rakudo. After the
optimizations i did to canonpath ~22 days ago the canonpath inclusive
time went down to about 18% ...

FILETEST-D and FILETEST-F are in spots 3 and 4, but they only take 3594
/ 26881 msec and 2749 / 216298 msec per invocation, so they are just
called really, really often.

next up is the loop from dir(), the one inside the gather. it sits at
10.44% inclusive time and 3.16% exclusive time.

dir itself takes 17.8% inclusive time and 3.12% exclusive time, which
seems to suggest it has a bit of overhead i'm not quite sure where to find.

match is up next at about 8.8% inclusive and 2.91% exclusive. I'm not
sure where exactly regex matches happen here; maybe a part of it comes
from canonpath.

AUTOTHREAD is at 12% inclusive time, which i find interesting. Perhaps
the reason is the test for dir, which by default is a none-junction.
Perhaps we can just use a little closure instead that eq's against . and
.. instead of going through a somewhat-more-expensive junction autothread.

That's all my thoughts for now.

@p6rt
Copy link
Author

@p6rt p6rt commented Nov 14, 2016

From @zoffixznet

As there have been improvements to the feature as well as discussions on the challenges faced to making it blazing fast, I'm going to close this ticket.

@p6rt
Copy link
Author

@p6rt p6rt commented Nov 14, 2016

@zoffixznet - Status changed from 'open' to 'resolved'

@p6rt p6rt closed this Nov 14, 2016
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
1 participant