Jump to content

LSL memory leak? Fragmentation?


animats
 Share

You are about to reply to a thread that has been inactive for 1674 days.

Please take a moment to consider if this thread is worth bumping.

Recommended Posts

I have a script which eventually gets a stack/heap collision after about an hour. It's part of a system of scripts, and its input is via a link message. It does lots of computation and list operations, and outputs data to other scripts using link messages.

It has no global variables of list or string types. All the list variables are local to functions. So it should not be able to leak memory. It does make lots of calls to the JSON functions, and calls llGetStaticPath, and I wonder if there are problems in those areas. Any known or suspected issues? I've checked the JIRA; nothing in recent years.

I'm logging some info, and here's what llGetFreeMemory is saying:

john@Nagle-LTS:~/Documents/sl/logs$ grep "Path planner low" lowonmem03.txt
[22:45] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:46] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:46] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:47] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:47] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:47] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:47] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:48] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:49] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:49] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:50] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:50] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:50] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:53] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:53] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:53] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:54] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:54] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:54] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:55] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:55] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:55] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:55] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:56] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:58] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:58] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:59] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[22:59] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[23:01] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[23:01] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[23:01] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[23:01] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2986
[23:03] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:04] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:04] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:05] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:05] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:07] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:07] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:07] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:08] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:09] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:09] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:09] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:10] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:10] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:10] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:12] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:12] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:13] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:14] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:15] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:16] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:16] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:16] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2472
[23:16] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:17] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:17] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:18] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:20] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:20] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:20] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:24] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:25] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:25] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:27] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:27] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:27] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:29] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:29] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:29] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:30] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:32] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:32] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:32] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:34] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:35] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:35] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:36] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:36] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:36] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 2258
[23:39] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:39] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:41] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:43] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:46] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:47] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:48] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:48] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:48] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:48] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:49] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:49] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:49] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:49] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:50] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:50] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:52] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[23:54] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[00:00] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[00:00] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[00:00] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[00:00] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[00:01] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[00:01] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[00:01] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278
[00:01] Dacy - NPC trainee 2.17c: Path planning: Path planner low on memory: 1278

And finally, in the debug window:

[00:03] Dacy - NPC trainee 2.17c [script:Path plan task] Script run-time error
[00:03] Stack-Heap Collision

The free memory ticking down looks like a leak. I've read that llGetFreeMemory can reflect free memory before the next garbage collection. When I saw free memory decreasing, I expected it to go back up at the next GC. But instead, I got a stack/heap collision.

Hm. Anyone seen something like this before?

 

 

 

  • Like 1
Link to comment
Share on other sites

Sounds like fragmentation left behind by string-intensive function calls, perhaps the JSON functions but could be anything. So what I do is find out how much memory the script uses before creating all the fragmentation, then when llGetFreeMemory() is getting low, I call llSetMemoryLimit to that pre-fragmentation value thus forcing gc, then set it back to the 64K maximum (65536), consolidating a block of free space between those two limit settings.

If you can't get llSetMemoryLimit to go down much below the 64K maximum, I'd suspect a real memory leak somewhere.

  • Like 1
Link to comment
Share on other sites

Well, I've been able to reproduce the problem with the same script and a test driver in a prim cube. Before, it was in a moving animesh NPC, and I had to chase it around to be close enough to see which script was getting a stack/heap collision. You have to be within llSay distance to get a DEBUG_CHANNEL popup box. Now the same single script is failing in a nice stationary cube. A little test driver script sends it link messages to make it go, and the results are discarded. Takes about 10-15 minutes to hit a stack/heap collision. The free memory, as reported by llGetFreeMemory, keeps decreasing as it runs. I've never seen it increase. It got down to 922 bytes. Then I printed the long output from a llGetStaticPath as a long string, and that apparently used up the remaining memory, causing a stack/heap collision.

The script spends most of its time in an idle waiting for event state, but going idle doesn't seem to shrink the memory used. Again, there are no global list or string variables, so it ought to return to its initial memory usage after each use. That's the obvious time for a garbage collection - when the script goes idle. No stack.

It's possible that some of the LSL calls like llgetStaticPath or the JSON calls allocate some internal space for the biggest item they ever processed, and don't release it. That would show a slow decrease in free space, like a memory leak, but it's bounded. Just speculation at this point.

This may take a while to chase down. More later.

Link to comment
Share on other sites

11 hours ago, animats said:

It's possible that some of the LSL calls like llgetStaticPath or the JSON calls allocate some internal space for the biggest item they ever processed, and don't release it. That would show a slow decrease in free space, like a memory leak, but it's bounded. Just speculation at this point.

what happens when comment out the llgetStaticPath ?

Link to comment
Share on other sites

There are 2 ways to make a stack/heap collision happen.

Allocate heap space. That isn't supposed to happen when you only use local variables. But maybe there are functions that always use heap space. If the heap memory is not marked as free - because the function is buggy or crashed while executing - then a garbage collection will NOT fix it.

The other way is to "forget" to reset the stack pointer. Do you have "return" statments or multiple ones in the middle of a function? I know this is supposed to work and I see it working but maybe you created a special scenario where it doesn't. A garbage collection will also NOT fix this of course.

 

Edited by Nova Convair
Link to comment
Share on other sites

LSL is single threaded - as long as an event or a function is processed - no other event will fire.

If processing is in an incarnation of a recursion that will block any other events.
If processing leaves this incarnation it will continue in the previous incarnation of that function and still block events.
The script will only continue to process events when all incarnations of the function are left. The stack is cleared then. So in the end it's no difference to any other non recursive function.

 

Link to comment
Share on other sites

1 hour ago, Love Zhaoying said:

My point is, recursion can also cause stack-heap collision errors.

Yes, insanely fast :) But not over time like it happens here. If the script continues to run then you have left the recursive stack.
You can't accumulate used memory on the stack that way in LSL. Either you crash or the recursion has ended. If processing stays in the function then you will have no events in that time.

Edit:

I get the impression that it's not known how recursion works. Example:

- We call a function - let's call the level we are in: incarnation 0
- Now the function calls itself - the processing happens in incarnation 1 now - same function
- Now we do it again - the processing is in incarnation 2.
- The function ends - but that means incarnation 2 stops to exist and is removed from the stack and the processing ends in incarnation 1 - at the next statement after the recursive function call.
- The function ends again - incarnation 1 is removed and the processing continues in incarnation 0
- The function ends again - now that we are leaving incarnation 0 the control goes back to the event where the function was called the 1st time.

As you can see - you can not leave until the whole stack on incarnations is worked off - you can not leave things back on the stack.
If that would be possible - LSL wouldn't be able to do recursion at all.
But LSL can do recursion!
So there are only 2 possibilities - the recursive call crashes your script - or leaves with a clean stack.

Edited by Nova Convair
Link to comment
Share on other sites

More testing. I let the NPC with this script run overnight. Free memory started around 10KB, and gradually decreased to about 3.5KB over half an hour. And then, over 10 hours, it didn't decrease any further. The script continued to run properly. No stack/heap collisions. So it's not an ongoing leak, it's some kind of slow startup transient or maximum usage.

I'm pretty sure my code isn't holding onto memory. In LSL, the only way you can do that is with a global list or string. This code (here) doesn't have either of those. I'm wondering if something within the LSL system calls sometimes allocates space and never gives it up. Not losing the space, just allocating a buffer for, say, the biggest llGetStaticPath or JSON parse or queued message. That would explain this. Anyone know?

Anyway, the take-away for this is that you can't get very close to the memory limit with long-running scripts. If they run busily for a day, they're probably OK.

As a backup, I now have another script with a stall timer. If the complicated planning scripts stop answering their link messages, the supervising script resets them all with llResetOtherScript. So far, that's tripped twice, for unrelated bugs, now fixed. This sort of supervision is common in real-world robotics. It's part of the price of long-running autonomy.

Quote

So there are only 2 possibilities - the recursive call crashes your script - or leaves with a clean stack.

Right. In LSL event-driven programs, if the script continues to accept events, it's getting all the way back to the stack empty state. LSL's limitations exclude many of the things that can go wrong in other languages.

 

Edited by animats
More info
Link to comment
Share on other sites

More info.

//
//  Memory allocation test - do we get free memory back?
//
integer listcnt = 13;
default
{
    touch_start(integer total_number)
    {   llOwnerSay("Free mem before allocating list: " + (string) llGetFreeMemory());
        list buf = [1];
        integer i;
        for (i=0; i<listcnt; i++)
        {   buf += buf;    }                         // double length of list   
        ////llSleep(0.5);     
        llOwnerSay("Free mem after allocating list of " + (string)llGetListLength(buf) + " integers: " 
            + (string) llGetFreeMemory());
        buf = [];                                   // release memory
        ////llSleep(0.5);     
        llOwnerSay("Free mem after releasing list: " + (string) llGetFreeMemory());
    }
}

Simple test program - allocates some memory, releases it, reports free memory.


 

[21:23] Free mem count test: Free mem before allocating list: 61140
[21:23] Free mem count test: Free mem after allocating list of 8192 integers: 56888
[21:23] Free mem count test: Free mem after releasing list: 56888

Touch again:

[21:23] Free mem count test: Free mem before allocating list: 56888
[21:23] Free mem count test: Free mem after allocating list of 8192 integers: 56888
[21:23] Free mem count test: Free mem after releasing list: 56888

This makes no sense. We allocated 8192 integers and memory space only dropped by 4252.

If the "llSleep" calls are not commented out, we get saner results:

[21.28] Free mem count test: Free mem before allocating list: 61140
[21:28] Free mem count test: Free mem after allocating list of 8192 integers: 28216
[21:28] Free mem count test: Free mem after releasing list: 28216


 

[21:28] Free mem count test: Free mem before allocating list: 28216
[21:28] Free mem count test: Free mem after allocating list of 8192 integers: 28216
[21:28] Free mem count test: Free mem after releasing list: 28216

 

Above, someone suggested forcing a garbage collection. Turns out that works.

//
//  Memory allocation test - do we get free memory back?
//
integer listcnt = 13;
default
{
    touch_start(integer total_number)
    {   llOwnerSay("Free mem before allocating list: " + (string) llGetFreeMemory());
        list buf = [1];
        integer i;
        for (i=0; i<listcnt; i++)
        {   buf += buf;    }                         // double length of list   
        llSleep(0.5);     
        llOwnerSay("Free mem after allocating list of " + (string)llGetListLength(buf) + " integers: " 
            + (string) llGetFreeMemory());
        buf = [];                                   // release memory
        llSleep(0.5);     
        llOwnerSay("Free mem after releasing list: " + (string) llGetFreeMemory());
        integer memlimit = llGetMemoryLimit();       // how much are we allowed?
        llSetMemoryLimit(memlimit-1);               // reduce by 1 to force GC
        llSetMemoryLimit(memlimit);                 // set it back
        llOwnerSay("Free mem after forcing GC: " + (string)llGetFreeMemory() + ". Memory limit: " + (string)memlimit);
    }
}

Results:

[21:50] Free mem count test: Free mem before allocating list: 60628
[21:50] Free mem count test: Free mem after allocating list of 8192 integers: 27700
[21:50] Free mem count test: Free mem after releasing list: 27700
[21:50] Free mem count test: Free mem after forcing GC: 60544. Memory limit: 65536

Now llGetFreeMemory increases. Changing the memory limit seems to force a garbage collection.

So it looks like:

  • llGetFreeMemory  gets updated on a "sleep", and
  • llGetFreeMemory does not increase even after releasing memory.
  • Reducing the memory limit, even by one byte, will force a garbage collection, which can increase llGetFreeMemory.

So, if you really need a free memory count before you allocate something big, that's how to get it. But it's undocumented behavior that might change. Any of the Lindens want to comment whether this is behavior that can be relied on?

Edited by animats
  • Like 2
  • Thanks 2
Link to comment
Share on other sites

I made a test.

1st thing I encounterd - 8192 integers do not fit into memory at all. Although I see NO error in your method of doubling the list - it obviously doesn't work.

//
//  Memory allocation test - do we get free memory back?
//
integer listcnt = 2047;
default
{
    touch_start(integer total_number)
    {   llOwnerSay("Free mem before allocating list: " + (string) llGetFreeMemory());
        list buf = [1];
        integer i;
        for (i=0; i<listcnt; i++)
        {   buf += [i];    }                         //   
        llSleep(0.5);     
        llOwnerSay("Free mem after allocating list of " + (string)llGetListLength(buf) + " integers: " 
            + (string) llGetFreeMemory());
        buf = [];                                   // release memory
        llSleep(0.5);     
        llOwnerSay("Free mem after releasing list: " + (string) llGetFreeMemory());
    }
}

And the result is:

[03:41] Object: Free mem before allocating list: 61140
[03:41] Object: Free mem after allocating list of 2048 integers: 28228
[03:41] Object: Free mem after releasing list: 28228
[03:41] Object: Free mem before allocating list: 28228
[03:41] Object: Free mem after allocating list of 2048 integers: 28228
[03:41] Object: Free mem after releasing list: 28228

The last 3 lines repeat over and over on every click.

So what happens:

- You need to use llSleep before you you llGetFreememory or you will not get a valid result.
- After adding 2048 single integers to the list the occupied memory is not freed
- On the next run there is no stack/heap collision - that means an automatic garbage collection was performed an so we can run this forever.

It makes no sense that you could allocate 8192 integers to the list.
Some math: an integer needs 4 bytes but every list element needs at least a pointer (4 bytes) and most probably some extra info like type flag and stuff not to mention a backward pointer so I don't see how 8192 elements will fit into 64k.
I've read that scripts can exceed the 64k limit for a short time - in this case a garbage collection is forced - and if the result is still over 64k a stack/heap error is generated. Probably this doesnt work like expected here.

Edit:

clicking after 15 mins gave this result:

[04:09] Object: Free mem before allocating list: 61140
[04:10] Object: Free mem after allocating list of 2048 integers: 28228
[04:10] Object: Free mem after releasing list: 28228

If seems that garbage collections are performed when the script idles long enough.

Edited by Nova Convair
  • Thanks 1
Link to comment
Share on other sites

4 hours ago, Nova Convair said:

Some math: an integer needs 4 bytes but every list element needs at least a pointer (4 bytes) and most probably some extra info like type flag and stuff not to mention a backward pointer so I don't see how 8192 elements will fit into 64k.

The wiki article on memory consumption claims 7 bytes per integer in a list. That's 57344 bytes, so it could fit. But the size numbers I got were:

12 hours ago, animats said:

[21:50] Free mem count test: Free mem before allocating list: 60628
[21:50] Free mem count test: Free mem after allocating list of 8192 integers: 27700

The difference there is 32928. Which works out to just over 4 bytes per integer.

I wonder how lists in LSL are really stored. They're probably not linked lists. More likely, collections. You can get elements by index, which is really slow for a linked list.

Link to comment
Share on other sites

10 hours ago, Nova Convair said:

And why can I only add 2048? Ok, some more but 8192 is far out of scope 
It's obviously 16 bytes per element in my example and 4 in your example.

Try building up the list by doubling, as I did.

Getting 4 bytes per element hints that there's a more efficient representation that it uses some of the time.

Link to comment
Share on other sites

You are about to reply to a thread that has been inactive for 1674 days.

Please take a moment to consider if this thread is worth bumping.

Please sign in to comment

You will be able to leave a comment after signing in



Sign In Now
 Share

×
×
  • Create New...