These are chat archives for ManageIQ/manageiq/performance

18th
Feb 2016
Keenan Brock
@kbrock
Feb 18 2016 02:14
@Fryguy so I'm looking at ancestry, and the "sorting" while bringing back ancestry values is bumping the query from 2ms to 50ms - doing an in memory sort.
Also noticed that we are not using an index.
since we are not using a c locale, using like 'X%' is doing an index scan. that may be simple enough to fix. not sure if we can swap indexes in 5.4
relationships.count == 122k, so not so big. but table scans are not so nice. especially when after the scan everything is loaded into memory for a quick sort.
yea, changing the index takes the query from 26ms -> 2ms
Keenan Brock
@kbrock
Feb 18 2016 16:42
Is there an easy way to show how much memory is used by our process? I was curious the difference before and after ManageIQ/manageiq#6594
will TOP be good enough?
Alex Krzos
@akrzos
Feb 18 2016 16:46
@kbrock Yeah I have a way
MiqProcess.processInfo()[:memory_usage]
Keenan Brock
@kbrock
Feb 18 2016 16:47
what I do I run that?
Alex Krzos
@akrzos
Feb 18 2016 16:48
you can surround your code blocks with that
Keenan Brock
@kbrock
Feb 18 2016 16:48
the memory will be taken up by GEMs
Alex Krzos
@akrzos
Feb 18 2016 16:48
for before/after
Keenan Brock
@kbrock
Feb 18 2016 16:48
so I guess I run that right after requiring the gems
thanks
Alex Krzos
@akrzos
Feb 18 2016 16:48
np otherwise you could just sample with smem while your running
Keenan Brock
@kbrock
Feb 18 2016 16:49
that sounds easier
can I do that from command line?
Joe Rafaniello
@jrafanie
Feb 18 2016 16:49
you can also use just the gem... Sys::ProcTable.ps(pid)
Keenan Brock
@kbrock
Feb 18 2016 16:50
k - thanks
@jrafanie did you have a chance to look at the PR yet?
Joe Rafaniello
@jrafanie
Feb 18 2016 16:50
not yet
Keenan Brock
@kbrock
Feb 18 2016 16:50
cool - thanks
Joe Rafaniello
@jrafanie
Feb 18 2016 16:50
trying to fix the builds
Keenan Brock
@kbrock
Feb 18 2016 16:50
lots to do...
huh. reloaded my database. sure enough. 54z is 15G, while master is 28G for the same database (just migrated)
Jason Frey
@Fryguy
Feb 18 2016 16:57

since we are not using a c locale, using like 'X%' is doing an index scan. that may be simple enough to fix. not sure if we can swap indexes in 5.4

That really surprises me. When I first wrote the ancestry stuff I made sure that the indexes were being used

and nothing has changed from that perspective
Keenan Brock
@kbrock
Feb 18 2016 16:57
I went into my db
did explains and played with it
added the different index, and it used it
Jason Frey
@Fryguy
Feb 18 2016 16:57
yeah me too :)
Keenan Brock
@kbrock
Feb 18 2016 16:57
but in the end, the ORDER is the culpret
different index can drop ~10%
Jason Frey
@Fryguy
Feb 18 2016 16:58
an index that is compatible with the ORDER?
Keenan Brock
@kbrock
Feb 18 2016 16:58
removing order is 60ms -> 2ms
I changed the query to order ancestry, AND ancestry like 'x/%'
Jason Frey
@Fryguy
Feb 18 2016 16:58
i think you are mixing 2 fixes in the same conversation and that is confusing
Keenan Brock
@kbrock
Feb 18 2016 16:58
didn't help
sorry
Jason Frey
@Fryguy
Feb 18 2016 16:59
when you say the order, you mean the ordered_by_ancestry method?
Keenan Brock
@kbrock
Feb 18 2016 16:59
I'm in sql
Jason Frey
@Fryguy
Feb 18 2016 16:59
yes, but what is generating that sql?
I ask because the ordered_by_ancestry is buggy IMO anyway
Keenan Brock
@kbrock
Feb 18 2016 16:59
high level - turn our ancestrs into a tree
Jason Frey
@Fryguy
Feb 18 2016 16:59
I have an open issue on it in the ancestry gem
huh? ancestry is a tree
stefankroes/ancestry#217 <- the issue I was talking about
Notice the last statement there
since i've rewritten arrangement, that no longer needs the ordered_by_ancestry method, so now we don't really need it.
Keenan Brock
@kbrock
Feb 18 2016 17:50
@Fryguy is that rewrite in ancestry or our code? has that been backported to 5.4?
I remember you doing it. but details are fuzzy
Jason Frey
@Fryguy
Feb 18 2016 18:27
I put a PR in the gem. @jrafanie said he was going to write an intializer for downstream
not sure on upstream...we can wait for a new gem, use a git ref...lots of choices
Joe Rafaniello
@jrafanie
Feb 18 2016 18:27
yeah, it's in my stash... not as easy because I can't just monkey patch it since it's included in the models
Keenan Brock
@kbrock
Feb 18 2016 18:28
@Fryguy ok - well, I upgraded my Gemfile for 5.4 and don't see much change
Joe Rafaniello
@jrafanie
Feb 18 2016 18:28
probably need to fork the old version and apply the change there
Jason Frey
@Fryguy
Feb 18 2016 18:29
yeha, I recall the benefits were not as good
...as expected
but, it does allow us to decouple ordered_by_ancestry from the arrangement
so it gives us the chance to remove the ordering
Keenan Brock
@kbrock
Feb 18 2016 19:06
@Fryguy Relationship.arranged_rels_to_resources ref is called a lot of times. takes a very long time in ruby.
sure, some time is spent in sql, but the sheer quantity of objects being created and being traversed, any thoughts on how to reduce this?
Jason Frey
@Fryguy
Feb 18 2016 19:07
not query them?
Relationship.arranged_rels_to_resources is doing its job...if the caller gives it 1000000 objects, it's going to retrieve all the objects
Keenan Brock
@kbrock
Feb 18 2016 19:08
no
the sql is not so bad
it is the recursive calls
Jason Frey
@Fryguy
Feb 18 2016 19:08
it should be doing it efficiently by preloading all the data
Keenan Brock
@kbrock
Feb 18 2016 19:08
and all the objects being created
yes
the sql is not so bad
Jason Frey
@Fryguy
Feb 18 2016 19:08
if you have a better way to do it, I'm all ears
how bad is it performance wise?
Keenan Brock
@kbrock
Feb 18 2016 19:08
I was surprised how much time is spent in here, and how many recursive calls are made
Jason Frey
@Fryguy
Feb 18 2016 19:09
not in # of calls, but in % time spent there in whatever you're trying to solve
recursion is always a lot of calls...that's kind of how it works
Keenan Brock
@kbrock
Feb 18 2016 19:10
page = 12k, arrange = 500+378+1397+1216+148
3,639/12k
almost all time in ruby
Jason Frey
@Fryguy
Feb 18 2016 19:10
arrange == arranged_rels_to_resources ?
Keenan Brock
@kbrock
Feb 18 2016 19:10
yes
Jason Frey
@Fryguy
Feb 18 2016 19:11
so 30% or so?
damn I lost my flame graph of this specific page :(
so, what are your thoughts to rewrite?
and is it 100% the arranged_rels_to_resources code or is there some other call deeper down that is the real culprit?