User talk:Philosopher/Nasal introspection: Difference between revisions

Jump to navigation Jump to search
m
→‎GC Issue: Too Many Objects!: like, uh, actually delete
m (→‎GC Issue: Too Many Objects!: like, uh, actually delete)
Line 122: Line 122:


—[[User:Hooray|Hooray]]
—[[User:Hooray|Hooray]]
== GC Issue: Too Many Objects! ==
Looking at Garbage collector stats in the logging output from FlightGear, there's a lot of GC'ing happening when loading scripts, which is okay. Essentially my (console-based) measure of “starting” the simulator that I see is when I see “Animated jetways ... initialized” message. Environment init happens somewhere in the middle, and test.nas in between those two subsystems. In both a “normal” and a “extended-nasal” (maybe it’s Extreme Nasal by now?) run, the environment init message is printed between GC reference counts of 26000-31000 (I saw +2000 extra objects for the run with test.nas compared to the normal one). In a test.nas run, the number of GC-findable objects keeps climbing from after I see “Start thread” and “End thread” messages. At the animated jetways init (after test.nas) I see 30340 versus 703425 objects (¡that's a factor of over 20!). In a normal session, the object count might keep going up until 43000, and then it drops off to 15000 and stays there for the rest of the session (15049 +- 20 or so). In an example test.nas session it got to 5268045 objects and an astounding 10645602 references (>1e7!) before I killed it off (couldn't bare to watch…). At that point, all of the worker threads were done, so it's not like they could be clinging to lost objects; and I'm not storing an infinitely-growing list anywhere, I'm even freeing the sub-contexts as they return! Since I know the Nasal code fairly well, is it possible that I'm creating leaks in the C code? But it is basically under the same automatic memory management, so I would think that it is unlikely. I will have to go a dump sizes of objects sometime, and perhaps whole namespaces, so that I can check if there's something that I'm forgetting to free. (Wait, I thought it was Nasal, we aren't supposed to worry about memory — wink.) Any thoughts? [[User:Philosopher|—Philosopher]] ([[User talk:Philosopher|talk]]) 21:02, 14 August 2013 (UTC)
:: As a crude workaround, you could expose the GC via an extension function, to explicitly trigger it in your code, and then watch the stats afterwards: IF the stats do not decrease after your explicit GC calls, objects are still somewhere referenced, i.e. cannot be reclaimed - maybe because of naTempSave() calls ? In general, memory isn't immediately reclaimed - but only after the GC could run, the amount of necessary GC work can be reduced by assigning nil and by delete()ing complex objects. Another thing worth trying would be associating naRefs with their origin (table of files and lines) using another naRef as a member, which would allow you to store the origin of naRefs directly inside them, and the dump everything to a file for inspection purposes. Adding an extension function that recursively dumps reachable naRefs (in a mark() fashion) should be straightforward and would tell us where the data came from that's still lingering around
::: If you can port your test.nas script to also work with the standalone interpreter in SG (no listeners, timers and systime), you could also just run it in valgrind (leak detector) which would tell you if the interpreter is leaking memory when running your script - use the nasal-shell if you don't have valgrind available locally.--[[User:Hooray|Hooray]] ([[User talk:Hooray|talk]]) 23:50, 14 August 2013 (UTC)
:::: I'll try that, since the issues don't go away when I delete the test namespace it's likely that I introduced a leak in the C side of things (which I still find odd). [[User:Philosopher|—Philosopher]] ([[User talk:Philosopher|talk]]) 00:07, 15 August 2013 (UTC)
::::: It's been a while since I ran nasal in valgrind, but IIRC Andy never frees his naPools, so you may need to explicitly call free on each pool at the end to ensure that valgrind isn't getting confused by Nasal's very own memory management. In case of doubt, run first a simple hello world program via valgrind/nasal and check if the output makes sense, if it doesn't, it's because of the GC pools, which may not be explicitly freed by the program at termination (which isn't too uncommon, because programmers generally rely on the OS to reclaim all allocated memory at program termination). Okay, just tried it via the shell (valgrind nasal-bin hello.nas):
<pre>
var x=[1,2,3];
var h={1:,2:,3:};
var foo = "foo";
==29457== Memcheck, a memory error detector
==29457== Copyright (C) 2002-2010, and GNU GPL'd, by Julian Seward et al.
==29457== Using Valgrind-3.6.0.SVN-Debian and LibVEX; rerun with -h for copyright info
==29457== Command: ./nasal-bin hello.nas
==29457==
==29457==
==29457== HEAP SUMMARY:
==29457==    in use at exit: 41,992 bytes in 81 blocks
==29457==  total heap usage: 255 allocs, 174 frees, 70,924 bytes allocated
==29457==
==29457== LEAK SUMMARY:
==29457==    definitely lost: 0 bytes in 0 blocks
==29457==    indirectly lost: 0 bytes in 0 blocks
==29457==      possibly lost: 7,408 bytes in 24 blocks
==29457==    still reachable: 34,584 bytes in 57 blocks
==29457==        suppressed: 0 bytes in 0 blocks
==29457== Rerun with --leak-check=full to see details of leaked memory
==29457==
==29457== For counts of detected and suppressed errors, rerun with: -v
==29457== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 4 from 4)
</pre>
BTW: Valgrind doesn't work too well with threads though ...
This trivial example worked in valgrind:
<pre>
var x=[1,2,3];
var h={1:,2:,3:};
var foo = "foo";
for(var i=0;i<=10;i+=1)
thread.newthread( func i );
</pre>


== Debugging Threads ==
== Debugging Threads ==
395

edits

Navigation menu