These are chat archives for ManageIQ/manageiq/performance

9th
Oct 2015
Matthew Draper
@matthewd
Oct 09 2015 00:12
@Fryguy @jrafanie the remaining ROOT appears to be due to the require in connect
Joe Rafaniello
@jrafanie
Oct 09 2015 00:39
Well, that makes no sense.. I'm sure there is a reason
Keenan Brock
@kbrock
Oct 09 2015 01:16
amazed how many instances of the same directory path they use up in strings in memory
and similar regular expressions
Joe Rafaniello
@jrafanie
Oct 09 2015 13:38
@matthewd where are we requiring 'net/telnet' ?
Matthew Draper
@matthewd
Oct 09 2015 13:38
@jrafanie we're not… that's just a simplified example, using something obscure from stdlib
Joe Rafaniello
@jrafanie
Oct 09 2015 14:56
@Fryguy can you throw your heap walker code up in a repo on github?
Jason Frey
@Fryguy
Oct 09 2015 14:57
sure
I working on making a full-=fledged gem that's actually usable...let me see if I can "undo" some of my breaking stuff to push it
shouldn't take more than a few minutes
Joe Rafaniello
@jrafanie
Oct 09 2015 15:02
ok
I added a README so you know how to use it
I changed it so the parsing takes less time, but I did that by deferring the indexing...so the first time you hit an index it takes a little while
Jason Frey
@Fryguy
Oct 09 2015 15:59
lol, for fun, I enabled parallel indexing...my machine went 7GB into swap :)
Oleg Barenboim
@chessbyte
Oct 09 2015 16:03
what is parallel indexing? Googling the term gets me lots of links to navigating a ship
Keenan Brock
@kbrock
Oct 09 2015 16:53
spotlight?
Jason Frey
@Fryguy
Oct 09 2015 16:53
no in my code there I added in the gem parallel and applied it to the indexing
which turned out to be a Bad Idea :tm:
Dennis Metzger
@dmetzger57
Oct 09 2015 18:29
nebula
Oleg Barenboim
@chessbyte
Oct 09 2015 18:29
@dmetzger57 ?
Jason Frey
@Fryguy
Oct 09 2015 18:30
Now we know his password? :laughing:
Dennis Metzger
@dmetzger57
Oct 09 2015 18:33
@chessbyte looking for me?
or just noticing that i was typing in the wrong window
actually wrong keyboard…...
Oleg Barenboim
@chessbyte
Oct 09 2015 18:37
had no idea what nebula was about
Dennis Metzger
@dmetzger57
Oct 09 2015 18:38
they are one of my favorite deep sky objects :smile:
Keenan Brock
@kbrock
Oct 09 2015 18:43
isn't nebula a red hat product too?
Joe Rafaniello
@jrafanie
Oct 09 2015 20:25
@matthewd @Fryguy
I have a question...
Jason Frey
@Fryguy
Oct 09 2015 20:25
:bulb:
Joe Rafaniello
@jrafanie
Oct 09 2015 20:25
So, the core refresh runner loads the @ems in the after_initialize ONCE :-)
It never gets freed... so all the FromUser FromDatabase, VimStrings never get collected
Jason Frey
@Fryguy
Oct 09 2015 20:26
the runner is the server side piece or the worker side piece?
FYI... this is a vmware refresher worker
[----] I, [2015-10-09T16:17:14.000661 #13239:3ffc9d05e1f8]  INFO -- : m:   6,314,332 | c:  31,801 | VimString
[----] I, [2015-10-09T16:18:16.315656 #13239:3ffc9d05e1f8]  INFO -- : m:   5,576,827 | c:  28,576 | VimString
[----] I, [2015-10-09T16:19:18.724519 #13239:3ffc9d05e1f8]  INFO -- : m:   5,576,827 | c:  28,576 | VimString
[----] I, [2015-10-09T16:20:21.229137 #13239:3ffc9d05e1f8]  INFO -- : m:   5,576,827 | c:  28,576 | VimString
[----] I, [2015-10-09T16:21:23.748865 #13239:3ffc9d05e1f8]  INFO -- : m:   5,576,827 | c:  28,576 | VimString
[----] I, [2015-10-09T16:22:26.331056 #13239:3ffc9d05e1f8]  INFO -- : m:   5,576,827 | c:  28,576 | VimString
[----] I, [2015-10-09T16:23:28.879699 #13239:3ffc9d05e1f8]  INFO -- : m:   5,576,827 | c:  28,576 | VimString
[----] I, [2015-10-09T16:24:31.450886 #13239:3ffc9d05e1f8]  INFO -- : m:   5,576,827 | c:  28,576 | VimString
[----] I, [2015-10-09T16:25:34.036806 #13239:3ffc9d05e1f8]  INFO -- : m:   5,576,827 | c:  28,576 | VimString
[----] I, [2015-10-09T16:26:36.598735 #13239:3ffc9d05e1f8]  INFO -- : m:   5,576,827 | c:  28,576 | VimString
[----] I, [2015-10-09T16:27:39.223679 #13239:3ffc9d05e1f8]  INFO -- : m:   5,576,827 | c:  28,576 | VimString
10 minutes later, the VimStrings are never collected
Because @ems never gets collected
was going to try something like this in the ManageIQ::Providers::BaseManager::RefreshWorker::Runner
  def do_gc
    ems_id = @ems.id
    @ems = nil

    super

    @ems = ExtManagementSystem.find(ems_id)
  end
note, as we found, there's no guarantees they'll be collected
Joe Rafaniello
@jrafanie
Oct 09 2015 20:35
@dmetzger57 ^^
Jason Frey
@Fryguy
Oct 09 2015 20:39
oh that's not the core runner
that the actual refresh worker base
Joe Rafaniello
@jrafanie
Oct 09 2015 20:39
whatever, it's runner.rb
learn to pluggable provider ;-)
Jason Frey
@Fryguy
Oct 09 2015 20:40
No, it's an important distinction
I thought you mean the core worker
totally different thing
so, the question is...does it need the EMS cached or can it find it fresh every time
Joe Rafaniello
@jrafanie
Oct 09 2015 20:41
yeah
Jason Frey
@Fryguy
Oct 09 2015 20:42
I think you can just pass an id EMS Refresh
so the worker can probably hold the id
and then call EmsRefresh.queue_refresh(ExtManagementSystem, @ems_id)
I think some other workers queue a refresh on start too
I'm so lost in this new layout :/
Joe Rafaniello
@jrafanie
Oct 09 2015 20:48
yeah, one thing at a time...
Jason Frey
@Fryguy
Oct 09 2015 20:50
I think the only thing you'll really run into is that the worker logging needs the ems
(which technically is wrong as is...if the hostname changes it will not get the new value)
Joe Rafaniello
@jrafanie
Oct 09 2015 20:50
So, the good news, is it's easy to tell
Jason Frey
@Fryguy
Oct 09 2015 20:50
yeah
:bomb:
Joe Rafaniello
@jrafanie
Oct 09 2015 20:51
[----] I, [2015-10-09T16:17:14.000513 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:17:14.000588 #13239:3ffc9d05e1f8]  INFO -- : m:   6,797,096 | c:  94,405 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:18:16.315559 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:18:16.315591 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,232 | c:  93,393 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:19:18.724423 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:19:18.724456 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,232 | c:  93,393 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:20:21.229040 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:20:21.229073 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,232 | c:  93,393 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:21:23.748762 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:21:23.748800 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,232 | c:  93,393 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:22:26.330965 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:22:26.330996 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,304 | c:  93,394 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:23:28.879605 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:23:28.879636 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,304 | c:  93,394 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:24:31.450788 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:24:31.450821 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,304 | c:  93,394 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:25:34.036714 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:25:34.036745 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,304 | c:  93,394 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:26:36.598610 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:26:36.598642 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,304 | c:  93,394 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:27:39.223581 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:27:39.223614 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,376 | c:  93,395 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:28:41.791208 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:28:41.791239 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,376 | c:  93,395 | ActiveRecord::Attribute::FromDatabase
[----] I, [2015-10-09T16:29:44.378213 #13239:3ffc9d05e1f8]  INFO -- : m:   6,946,056 | c:  96,473 | ActiveRecord::Attribute::FromUser
[----] I, [2015-10-09T16:29:44.378245 #13239:3ffc9d05e1f8]  INFO -- : m:   6,724,376 | c:  93,395 | ActiveRecord::Attribute::FromDatabase
Jason Frey
@Fryguy
Oct 09 2015 20:51
is that good? ¯\_(ツ)_/¯
Joe Rafaniello
@jrafanie
Oct 09 2015 20:51
If we're accumulating those Objects, it means we have objects in memory that aren't getting freed, so values we stored/got in/from the database
no, that's the bad one
Jason Frey
@Fryguy
Oct 09 2015 20:52
ah gotcha
Joe Rafaniello
@jrafanie
Oct 09 2015 20:54
Maybe we should log the count of those two types in debug, if they're remaining around in a worker, it means we have an object in memory in the worker that never goes away
Jason Frey
@Fryguy
Oct 09 2015 20:54
Actually huge step back
The worker does not use that @ems for refresh
It is a queue worker, so it works on whatever object is from the queue and then should throw it away
It's not a problem that the worker holds an EMS, because it should never get large, and it prevents having to go back to the database over and over...in this case it's a "good" kind of cache
so, although it may have a couple of attributes, it will not have the entire tree of data inside it
Joe Rafaniello
@jrafanie
Oct 09 2015 20:57
hmm, it does though... I nil that guy out, let it GC, and re-fetch it and the temporary objects go away
Jason Frey
@Fryguy
Oct 09 2015 20:57
is this a side effect of the bug @matthewd just fixed?
Joe Rafaniello
@jrafanie
Oct 09 2015 20:58
I"m running with 4-2-stable
Jason Frey
@Fryguy
Oct 09 2015 20:59
let's jump on a call because that makes no sense
Joe Rafaniello
@jrafanie
Oct 09 2015 20:59
one, second, deep in something
Jason Frey
@Fryguy
Oct 09 2015 21:01
k
it calls EmsRefresh.queue_refresh, which, unless I'm mistaken, doesn't get the whole tree just to put the id on the queue
Joe Rafaniello
@jrafanie
Oct 09 2015 21:17
ok, good, GC is making me a liar, no idea why pid 13239 never GC'd those objects
Jason Frey
@Fryguy
Oct 09 2015 21:17
ah ok
still, wish you had found it :/
Joe Rafaniello
@jrafanie
Oct 09 2015 21:35
GC's timing is garbage