<div dir="ltr">I tried to put together a small sample that was similar to what ruby is actually doing. In the attached sample I set up a similar structure vm with list of pages and each page had a list of objects. The only thing on the object is a int flag that I just increment so when I print it out in python and can gauge progress. In the python script then I try to time each call in the loop and print that out as well. The time it takes each time through the loop seems to get higher and higher even though FindFirstGlobalVariable is only called once.<div>
<br></div><div>Thanks,</div><div>Scott Knight</div></div><div class="gmail_extra"><br><br><div class="gmail_quote">On Thu, Apr 17, 2014 at 8:50 PM, Greg Clayton <span dir="ltr"><<a href="mailto:gclayton@apple.com" target="_blank">gclayton@apple.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">How many objects are we talking about here?<br>
<br>
On Apr 17, 2014, at 5:46 PM, Scott Knight <<a href="mailto:knightsc@gmail.com">knightsc@gmail.com</a>> wrote:<br>
<br>
> So when I call my "ruby objects" command it will create an instance of my RubyObjects class and call invoke on it once. In the invoke is where I have this call<br>
><br>
> self.ruby_current_vm = lldb.value(lldb.target.FindFirstGlobalVariable('ruby_current_vm'))<br>
><br>
> Then in print_stats it calls into all_objects which does this<br>
><br>
><br>
> def all_objects (self):<br>
> self.heaps_used = self.ruby_current_vm.objspace.heap_pages.used<br>
><br>
> for i in xrange(self.heaps_used):<br>
> page = self.ruby_current_vm.objspace.heap_pages.sorted[i]<br>
> print "page %i" % i<br>
><br>
> for j in xrange(page.limit):<br>
> rvalue = page.start[j].__getattr__('as')<br>
> flags = rvalue.basic.flags<br>
> yield rvalue, flags<br>
><br>
> So self.ruby_current_vm should already be reused. If I stop the loop through page.limit everything is fast, but with the code within that second for loop things just slow down more and more.<br>
><br>
> -Scott<br>
><br>
><br>
> On Thu, Apr 17, 2014 at 8:40 PM, Greg Clayton <<a href="mailto:gclayton@apple.com">gclayton@apple.com</a>> wrote:<br>
> Since you are dealing with a global, you are not tied to a stack frame, so you should be able to cache this value and re-use it:<br>
><br>
><br>
><br>
> if not self.ruby_current_vm:<br>
> self.ruby_current_vm = lldb.value(lldb.target.FindFirstGlobalVariable('ruby_current_vm'))<br>
><br>
> Then you should be able to use this over and over without re-fetching it. And you should be really fast. Each time you fetch a variable from SBTarget::FindFirstGlobalVariable(), it re-wraps the variable in a new VariableObjectSP which has its own cluster manager. Why? Because you might do something like:<br>
><br>
> f = lldb.value(lldb.target.FindFirstGlobalVariable('g_ptr'))<br>
><br>
> f = f.a.b.c.d<br>
><br>
> Now we need a reference to the ValueObjectSP for "g_ptr" (the underlying variable that roots the entire expression) to stay alive as long as anyone has a reference to anything that is a child of "g_ptr". Here "f" now reference "g_ptr->a.b.c.d", so any value in this chain is correctly reference counted using a ClusterMananger that keeps all of them alive as long as someone has a reference to any of them.<br>
><br>
> So if you reuse your "self.ruby_current_vm", you should only have a single ClusterManager and they should stay shared as long as you use them. Currently you are re-creating the root with each call and then referencing a bunch of children which adds new shared references to each cluster manager.<br>
><br>
> Let me know how reusing the one instance goes.<br>
><br>
> Greg<br>
><br>
><br>
> On Apr 17, 2014, at 5:22 PM, Scott Knight <<a href="mailto:knightsc@gmail.com">knightsc@gmail.com</a>> wrote:<br>
><br>
> > I attached the instruments trace here in case it might be helpful. Seems like a lot of time is spent in the ClusterManager. It seems like thats called from all the ValueObject. I do realize that I'm getting values over and over again in a loop, but it seems to just take longer each time through the loop. I also attached the python script I'm using in the zip file as well.<br>
> ><br>
> > -Scott<br>
> ><br>
> ><br>
> > On Thu, Apr 17, 2014 at 7:56 PM, Greg Clayton <<a href="mailto:gclayton@apple.com">gclayton@apple.com</a>> wrote:<br>
> > No idea. If you are running this on MacOSX, I would run a time profile in instruments on it and see what is going on.<br>
> ><br>
> > On Apr 17, 2014, at 4:32 PM, Scott Knight <<a href="mailto:knightsc@gmail.com">knightsc@gmail.com</a>> wrote:<br>
> ><br>
> > > Any of idea why making that call over and over again would seem to slow down over time?<br>
> > ><br>
> > > -Scott<br>
> > ><br>
> > > On Apr 17, 2014 7:29 PM, "Greg Clayton" <<a href="mailto:gclayton@apple.com">gclayton@apple.com</a>> wrote:<br>
> > > Yep, it is the python keyword... You currently need to use your workaround:<br>
> > ><br>
> > > rvalue.__getattr__("as")<br>
> > ><br>
> > > Glad we found it and that there is nothing wrong with the API (we are finding children of anonymous unions, phew!).<br>
> > ><br>
> > > Greg<br>
> > ><br>
> > > On Apr 17, 2014, at 3:46 PM, Scott Knight <<a href="mailto:knightsc@gmail.com">knightsc@gmail.com</a>> wrote:<br>
> > ><br>
> > > > typedef struct RVALUE {<br>
> > > > union {<br>
> > > > struct {<br>
> > > > VALUE flags; /* always 0 for freed obj */<br>
> > > > struct RVALUE *next;<br>
> > > > } free;<br>
> > > > struct RBasic basic;<br>
> > > > struct RObject object;<br>
> > > > struct RClass klass;<br>
> > > > struct RFloat flonum;<br>
> > > > struct RString string;<br>
> > > > struct RArray array;<br>
> > > > struct RRegexp regexp;<br>
> > > > struct RHash hash;<br>
> > > > struct RData data;<br>
> > > > struct RTypedData typeddata;<br>
> > > > struct RStruct rstruct;<br>
> > > > struct RBignum bignum;<br>
> > > > struct RFile file;<br>
> > > > struct RNode node;<br>
> > > > struct RMatch match;<br>
> > > > struct RRational rational;<br>
> > > > struct RComplex complex;<br>
> > > > struct {<br>
> > > > struct RBasic basic;<br>
> > > > VALUE v1;<br>
> > > > VALUE v2;<br>
> > > > VALUE v3;<br>
> > > > } values;<br>
> > > > } as;<br>
> > > > #if GC_DEBUG<br>
> > > > const char *file;<br>
> > > > VALUE line;<br>
> > > > #endif<br>
> > > > } RVALUE;<br>
> > > ><br>
> > ><br>
> ><br>
> ><br>
> > <lldb-cpu-time.zip><br>
><br>
><br>
<br>
</blockquote></div><br></div>