Re: [Flightgear-devel] Profiling run
Andy Ross writes: These are clearly related to texture loading. How long did you run your profiler for? If it was just for a few seconds, then these might be showing the time spent in initialization and not in the routine frame-to-frame running of the program. Certainly, parsing and generating textures is going to be expensive at startup. I ran it for only 30 seconds. I'll do another run for 5 minutes, with an actual flight, and report the results. All the best, David -- David Megginson [EMAIL PROTECTED] ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel
Re: [Flightgear-devel] Profiling run
On Wed, 27 Feb 2002 11:28:01 -0500 David Megginson [EMAIL PROTECTED] wrote: The good news is that the JSBSim matrix support isn't showing up on the radar screen any more. Thanks to the work by Norman and Tony (IIRC). I think we can still make some improvements in JSBSim and I want to try profiling JSBSim in standalone mode again soon. Jon ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel
Re: [Flightgear-devel] Profiling run
Tony Peden writes: It seems very strange to me, however, that FGInterface::operator= would show up at all. According to that output, it was called almost 200,000 times. What's up with that? Do we keep two copies and swap between them? All the best, David -- David Megginson [EMAIL PROTECTED] ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel
Re: [Flightgear-devel] Profiling run
On Wed, 2002-02-27 at 10:59, Tony Peden wrote: On Wed, 2002-02-27 at 10:22, David Megginson wrote: Tony Peden writes: It seems very strange to me, however, that FGInterface::operator= would show up at all. According to that output, it was called almost 200,000 times. What's up with that? Do we keep two copies and swap between them? At one time we did, there's a cur_fdm_state and a base_fdm_state declared in flight.cxx. There don't appear to be any references to base_fdm_state left anymore, however, so I don't think that would trigger the operator= Just grepping through the code, it would seem that there are a couple of possibilities in main.cxx and native.cxx. As soon as I get my tree running again I'll try and chase them down. All the best, David -- David Megginson [EMAIL PROTECTED] ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel -- Tony Peden [EMAIL PROTECTED] We all know Linux is great ... it does infinite loops in 5 seconds. -- attributed to Linus Torvalds ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel -- Tony Peden [EMAIL PROTECTED] We all know Linux is great ... it does infinite loops in 5 seconds. -- attributed to Linus Torvalds ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel
RE: [Flightgear-devel] Profiling run
On Wed, 2002-02-27 at 09:00, Vallevand, Mark K wrote: I probably doesn't get called that many times. Most profiling software picks up some cruft. There is probably some bit of code located just after FGInterface::operator= that *is* called a lot, but doesn't have any debug information associated with it. So, as far as the profiler is concerned, its part of FGInterface::operator=. I see this all the time in the profiles I do here at work. Even with compiler generated operator=? Regards. Mark K Vallevand Fat, dumb and happy. 2 out of 3 ain't bad. It seems very strange to me, however, that FGInterface::operator= would show up at all. According to that output, it was called almost 200,000 times. What's up with that? ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel -- Tony Peden [EMAIL PROTECTED] We all know Linux is great ... it does infinite loops in 5 seconds. -- attributed to Linus Torvalds ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel
Re: [Flightgear-devel] Profiling run
David wrote:
For example, the
program spent 2.95% of its time in ssgVtxTable::getNumVertices,
This simply calls getNum of the list, which simply returns a member
variable:
int getNum (void) { return total ; }
See ssg.h.
David
Bye bye,
Wolfram.
___
Flightgear-devel mailing list
[EMAIL PROTECTED]
http://mail.flightgear.org/mailman/listinfo/flightgear-devel
RE: [Flightgear-devel] Profiling run
Well, no, not specifically with operator=. But, my point is that operator= might not be involved. It also depends on the kind of profiler used. If its a profiler that is enabled with compiler switches and code to count calls is compiled in, then my point is not valid. However, some profilers poll the instruction pointer, or use the processor itself to capture profile data. The profiler has to associate an address with a function and sometimes gets it wrong. funca: code code ... ret code - what function is this address in? code funcb: code code ... jmp funcb-2 code ret I've seen this many times. Funca is getting counts that are really for funcb. Regards. Mark K Vallevand Fat, dumb and happy. 2 out of 3 ain't bad. -Original Message- From: Tony Peden [mailto:[EMAIL PROTECTED]] Sent: Wednesday, February 27, 2002 1:26 PM To: FGFS Devel Subject: RE: [Flightgear-devel] Profiling run On Wed, 2002-02-27 at 09:00, Vallevand, Mark K wrote: I probably doesn't get called that many times. Most profiling software picks up some cruft. There is probably some bit of code located just after FGInterface::operator= that *is* called a lot, but doesn't have any debug information associated with it. So, as far as the profiler is concerned, its part of FGInterface::operator=. I see this all the time in the profiles I do here at work. Even with compiler generated operator=? Regards. Mark K Vallevand Fat, dumb and happy. 2 out of 3 ain't bad. It seems very strange to me, however, that FGInterface::operator= would show up at all. According to that output, it was called almost 200,000 times. What's up with that? ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel -- Tony Peden [EMAIL PROTECTED] We all know Linux is great ... it does infinite loops in 5 seconds. -- attributed to Linus Torvalds ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel
Re: [Flightgear-devel] Profiling run
On Wed, Feb 27, 2002 at 01:59:27PM -0600, Vallevand, Mark K wrote: Well, no, not specifically with operator=. But, my point is that operator= might not be involved. It also depends on the kind of profiler used. If its a profiler that is enabled with compiler switches and code to count calls is compiled in, then my point is not valid. I suspect, but don't know for sure, that David used the -p switch to g++. So maybe it really is operator= However, some profilers poll the instruction pointer, or use the processor itself to capture profile data. The profiler has to associate an address with a function and sometimes gets it wrong. funca: code code ... ret code - what function is this address in? code funcb: code code ... jmp funcb-2 code ret I've seen this many times. Funca is getting counts that are really for funcb. Regards. Mark K Vallevand Fat, dumb and happy. 2 out of 3 ain't bad. -Original Message- From: Tony Peden [mailto:[EMAIL PROTECTED]] Sent: Wednesday, February 27, 2002 1:26 PM To: FGFS Devel Subject: RE: [Flightgear-devel] Profiling run On Wed, 2002-02-27 at 09:00, Vallevand, Mark K wrote: I probably doesn't get called that many times. Most profiling software picks up some cruft. There is probably some bit of code located just after FGInterface::operator= that *is* called a lot, but doesn't have any debug information associated with it. So, as far as the profiler is concerned, its part of FGInterface::operator=. I see this all the time in the profiles I do here at work. Even with compiler generated operator=? Regards. Mark K Vallevand Fat, dumb and happy. 2 out of 3 ain't bad. It seems very strange to me, however, that FGInterface::operator= would show up at all. According to that output, it was called almost 200,000 times. What's up with that? ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel -- Tony Peden [EMAIL PROTECTED] We all know Linux is great ... it does infinite loops in 5 seconds. -- attributed to Linus Torvalds ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel -- Tony Peden [EMAIL PROTECTED] We all know Linux is great ... it does infinite loops in 5 seconds. -- attributed to Linus Torvalds ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel
Re: [Flightgear-devel] Profiling run
calc_magvar() is interesting ... that might be something we wouldn't have to do every frame ... For what this may be worth, where I work (Rockwell Collins), we do mag var computations about once every two minutes. Even given some of the aircraft for which we design (KC-135, B-1B, 747), mag var changes very slowly. Jonathan Polley ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel
Re: [Flightgear-devel] Profiling run
David Megginson wrote: I did another run, with a flight of over one hour on autopilot. Cumulatively, ssgEntity::cull_test and ssgBranch::cull use nearly 20% of CPU time -- that's OK, as long as the framerate improvements justify the work. Yes - that's probably not too bad...but with it narrowed down that closely, you can probably squeeze some performance out of them. Probably, most of that time is actually spent in int sgFrustum::contains ( const sgSphere *s ) ...my Scene graph API that I wrote for use at work is quite a but cleverer about how it does this. The 'contains' test in SG measures the distance from the center of the sphere to each of the four planes of the view frustum. In fact, you can improve on this by remembering which faces of the frustum the PARENT OBJECT SPHERE's passed cleanly and not bother to test against them in future. You end up needing to write about 64 different functions - each hand-optimised to test a sphere against a different combinations of the six faces of the frustum. Then you can compute a number that indicates to objects lower in the tree which version of that function to call when they need to test their spheres. This results in most spheres' not needing to be tested at all - and for those that do need to be tested, most need only one sphere-to-plane calculation. That's quite a lot of typing - but it's not actually that hard to do. I can see room for some easy plib optimizations. For example, the program spent 2.95% of its time in ssgVtxTable::getNumVertices, 1.91% of its time in ssgVtxTable::getNumColours and 1.8% of its time in ssgVtxTable::getNumTexCoords. All of these might be able to be optimized to cache the result, rather than counting through the arrays each time (if they do that currently), and it looks like the saving could be significant. That certainly seems like a VERY big number - but all of those routines are simply fetching a member variable via a pointer. They are declared 'inline' - but since they are probably also 'virtual' that may still result in a function call. The only way I can imagine they are consuming that much time would be if they are called a heck of a lot of times. Probably there are some loops: for ( int i = 0 ; i getNumVertices() ; i++ ) ...whatever... ...so 'getNumVertices' get called (unnecessarily) in every loop. It might be worth copying the value into a variable first or even running the loop backwards to avoid calling the function every time. On our side, the biggest hog is FGHitList::IntersectBranch, with 3.96% of CPU time. I assume that's calculating the ground elevation, but any optimizations might be helpful, if people can think of one. In my experience, there are often some great ways to optimise those kinds of functions. But guys - get this into perspective. If you take a routine that consumes only 1% of the CPU and you make it go 100 times faster, how much faster does the program run? Less than 1% faster. It's not worth the effort to do that unless you think you can get comparable speedups in every single function in the program. All you can possibly do is to optimise things that are up there in the 20% range...and even then, you won't do much to improve performance...you'll never manage to double the speed of the program for example! If you don't see things consuming considerably more than 20% of the CPU, you need to look for major *structural* improvements rather than line-by-line optimisations. - Steve Baker --- Mail : [EMAIL PROTECTED] WorkMail: [EMAIL PROTECTED] URLs : http://www.sjbaker.org http://plib.sf.net http://tuxaqfh.sf.net http://tuxkart.sf.net http://prettypoly.sf.net http://freeglut.sf.net http://toobular.sf.net http://lodestone.sf.net ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel
Re: [Flightgear-devel] Profiling run
Wow, good stuff. Skimming through to apply my own intuition: 6.99% ssgEntity::cull_test 5.28% ssgBranch::cull 4.85% ssgVtxTable::draw_geometry 3.42% FGHitList::IntersectLeaf 3.28% FGHitList::IntersectBranch 2.85% ssgVtxTable::getNumVertices 2.71% sgFrustum::contains 1.85% sgdPointInTriangle 1.28% sgdClosestPointToLineDistSquared 1.28% ssgSimpleState::apply These guys are all directly related to the rendering process, and are where we should expect to spend our time. The only odd one I see is ssgVtxTable::getNumVertices. I don't care how many times that's called, how does returning an integer figure in global performance? Maybe it's a profiler interaction. 8.84% sgdMakeNormal This one is notable only because it's so expensive. Sometimes, you just have to normalize something before passing it to OpenGL, and you have to eat the cost. As far as I know, all of our geometry is fixed and we don't use funny scalings. So most stuff shouldn't require per-frame normalization. This looks to me like a good spot to concentrate on; I'll bet most or all of these calls can be eliminated with a little work. 17.40% ssgMakeMipMaps 1.57% ssgSGIHeader::ssgSGIHeader[in-charge] 1.43% ssgSGIHeader::getRow These are clearly related to texture loading. How long did you run your profiler for? If it was just for a few seconds, then these might be showing the time spent in initialization and not in the routine frame-to-frame running of the program. Certainly, parsing and generating textures is going to be expensive at startup. 2.14% calc_magvar This has me stumped too. First, why on earth is it being called so much? I'd think once per frame would be more than sufficient. Second, this is (or should be) an rather cheap computation. A few hundred CPU cycles at most. Weird. Andy -- Andrew J. RossNextBus Information Systems Senior Software Engineer Emeryville, CA [EMAIL PROTECTED] http://www.nextbus.com Men go crazy in conflagrations. They only get better one by one. - Sting (misquoted) ___ Flightgear-devel mailing list [EMAIL PROTECTED] http://mail.flightgear.org/mailman/listinfo/flightgear-devel
