MONO's llGetFreeMemory Issue (racer X edition)

wanna see a Script that can't make up it's mind?
report free memory first thing from a mono script in the state entry. then automatically reset the script a few dozen times....

integer gIntMemBase;
integer gIntCounter;

default{
    state_entry(){
        llOwnerSay( "/me " + (string)(gIntMemBase = llGetFreeMemory() - 0));
        llSetTimerEvent( 0.0 );
        gIntCounter = (integer)(llGetAlpha( 0 ) * 50);
        if (gIntCounter > 0) {
            llSetAlpha( --gIntCounter / 50.0, 0 );
            llOwnerSay( "/me " + (string)(llGetFreeMemory() - gIntMemBase) );
            llResetScript();
        }
        llSetAlpha( 1.0, 0 );
        llOwnerSay( "/me Done" );
    }
}

want to make it behave consistently?
force it to slow down, and bam, one odd jump from the front, and the rest fall in line....

integer gIntMemBase;
integer gIntCounter;

default{
    state_entry(){
        llSetTimerEvent( 0.001 );
    }
    
    timer(){
        if (!gIntMemBase){
            llOwnerSay( "/me " + (string)(gIntMemBase = llGetFreeMemory() - 0));
        }else{
            llSetTimerEvent( 0.0 );
            gIntCounter = (integer)(llGetAlpha( 0 ) * 50);
            if (gIntCounter > 0) {
                llSetAlpha( --gIntCounter / 50.0, 0 );
                llOwnerSay( "/me " + (string)(llGetFreeMemory() - gIntMemBase) );
                llResetScript();
            }
            llSetAlpha( 1.0, 0 );
            llOwnerSay( "/me Done" );
        }
    }
}

conclusion?
there's a race condition somewhere between the mono compiler and sim VM, and it's guaranteed to be several bytes off between the first and second compile (I've had 28, 32, and 48, all consistently for a specific compile, looks like event code is affecting it.)

(this is just ONE of several inconsistencies in MONO)

I'm not particularly worried about a 10 instruction inconsistency, except for cases where I'm trying to compare byte code efficiency. For that case, I'll be sure to avoid the issue using your workaround. But it *is* important to know, so thanks for posting!

Not sure what you mean by "there's a race condition somewhere between the mono compiler and sim VM, and it's guaranteed to be several bytes off between the first and second compile".

For now, let's forget the mono compiler. Once code is compiled, it's compiled. Now, maybe object code can be different size for different compiles, due to say, including a timestamp and compressing it (for a silly example). But, that would just cause a difference between compiles: running the same compiled object would yield the same size of object code every time. If there *is* a difference caused by recompiling, that would be good to know, but not a major issue. Given your workaround, this can be measured.

So the question remains as to why there's an inconsistent result in the state_entry() handler. This doesn't happen in the trivial case, btw. Might be useful to find the *minimum* script that shows a discrepancy.

What I find is that the first result, directly after compiling (in and object, currently the only way to compile Mono), differs from subsequent resets, but all subsequent resets are consistent. For example:

default
{
    state_entry() {
        llOwnerSay((string)llGetFreeMemory());
    }
}

Always gives the same value when recompiled, and always gives the same value when reset. This implies to me that the process that runs code immediately after a compilation takes a few extra bytes (not a race condition, where we'd see inconsistent results).

The difference I'm seeing between reset on compile versus reset is consistently 24 bytes.

I see, it's not quite as consistent as I thought. Sometimes I see the 24-byte discrepancy on a reset, but only in the state_entry handler.

default
{
    state_entry() {
        llOwnerSay((string)llGetFreeMemory());
        llResetScript();
    }
}

The above produces inconsistent results (varying by 24 bytes). The following is consistent, after the first time:

default
{
    state_entry() {
        llSetTimerEvent(0.05);
    }
    timer() {
        llOwnerSay((string)llGetFreeMemory());
        llResetScript();
    }
}

I get similar results in a touch or state_exit handler, and the discrepancy returns in a subsequent state's entry handler. Perhaps the lesson here is, don't test for free memory in the state_entry handler and expect the results to be deterministic.

the first call nails down the compile size, the second one bytes that have been used since the compile check.

the race condition (actually it must be in the VM) is noticeable when you run the first version, as the stats can and do jump around (if it stays consistent over a rew tries, do a whitespace edit and save it again, occasionally the VM will run slow enough that it misses the condition.)

the second script version shows that with a slight delay after reset the results are no longer ramdomy different (becase it's not beating the race condition).

24 huh? for fun, edit the name of the prim to a single space and reset the script... see if anything changes... I'm curious to figure out WHAT the difference in the code length is representative of.

I edited my reply, see above.

We can't assume it's a race condition. It might be, but so far all we know is it's an inconsistency.

We don't know it's a difference in the code length. I believe it's not, because the code length doesn't change after compilation.

The object name doesn't factor in for my tests, but I'm not using "/me", which might matter.

unfortunately that's the only place where you can get accurate compile size readings. any code after that can throw it off, including other handlers. some things will and others won't, but anything that throws both initial and post term calculation off is a problem.

I choose to post about this one because I've got a solid test that demonstrates clear and reproducible data. (although the size thing is seriously throwing me...)

can't think of any other plausible explanation... guaranteed difference out of a fresh compile, and random differences when the speed version of the code is run, but not when the moderated one is.

If I were to guess I'd saw it's somewhere in the serialization, compile rebuilds the serialization, but reset only seems to refresh it, and somethings not getting changed in time to show up for the free mem call... something that only gets put into place when the script first comes to it, and gets written late on the reset.... the script time counter maybe? FIIK.

ETA
BAM!!
on a hunch I threw in a call to reset the script time to force instantiation and what did I find... the first pass discrepancy after compile disappears. the speed verion vs timer moderated version still shows something not keeping up... but at least we have on part solved (I think)

default{
    state_entry(){
        llResetTime();
        llSetTimerEvent( .001 ); //-- replace with timer code to see race condition changes.
    }
    
    timer(){
        llOwnerSay( (string)llGetFreeMemory() );
        llResetScript();
    }
}

Unless I'm comparing binary sizes to help "peephole optimizing", I rarely care about just the binary size, and care much more about the total size with a big config. That way I can tell whether my code/data space tradeoffs are helping.

But sometimes we do want to know code size, so it's useful to know that the results can be off (by 24 in all cases I tested; YMMV).

We have an apparent nondeterminacy. Race conditions are one cause, but not the only one. A very common one is an uninitialized local variable.

To have a race condition, you need at least two entities -- there has to be some parallelism. What entities in this case? I'd have to make lots of guesses. But without knowing who the runners are, it's not particularly helpful to talk about it.

In any case, it's best to discuss the symptom and not assume the cause until we have solid evidence. Otherwise we blind ourselves to the possibilities.

I see a 24-byte difference between first run after compile versus the remainder.

it might be something else, I'm just giving myself a direction to look in... and trying to invent creative ways to ferret out the exact cause. my current guess is based on the fact that the memory increases not decreases (although I suppose a variant traded in for an integer would have a similar effect) with the thought that it may be a late addition of the script time variable to the scripts space, by the VM... but I can only guess what is and isn't done when the script is initialized for run by the VM.

that last script still gives you a discrepancy on first run? hmmm... try something stupid for me and make the timer delay bigger if you play with it again? it's showing 100% from first compile on this sim, one of the new 1.26.4's (not that they mention anything relevant in the release notes)

thanks for your help playing with this. I've opened a Jira, but may need to edit it.

My guess is that the compile size differences could be a versioning artifact. Presumably LL is using GAC to do the code sharing thing, and the metadata that gets tacked on can vary a little in size.

Tori, that's a possibility for the first compile bug... although is means that information is being read as part of the script sometimes? that can't be good, there'd be a potential for collisions and bad data (not that those wonderful MONO error messages would indicate anything like that :nicker: although why forcing the script time variable to be written would help points to other things (assuming that is working, it did for me, Lear had different results.)

I'm running out of new ideas to try.

Good hypothesis, but I don't think we see a "compile size difference".

All I've seen is a diffence in free space between a just-compiled script and a script that has been reset after its first compilation. So far I haven't noticed a difference in size that can be attributed to recompiling alone. But perhaps there is, and if so, the metadata is definitely a good candidate.

What's GAC? Are you referring to .NET Global Assembly Cache? I don't know anything about that.

Void, we should both be reporting which server version we're using for our tests. Unfortunately I didn't make a note of mine before, and rolling restarts are in progress. I'll retest when I get a chance.

all those test were 1.26.4 for me, as I retested them all after the rolling restart (and actually got hit on my testing sim twice)

PS (seems I'm not the only one that tests via alt =X)

as for WHY I've latched on to this? it's just one of the misbehavior's of get free mem in mono, and contributes to making it overall unreliable for larger stuff... if we can remove the testable inconsistencies, we have a better chance of finding the rest, and making the function useful again, and remove one more block from LSO to MONO conversion. never mind that we can then use the function to reliably test other memory related errors withon mono in an accurate manner.

OK, I think I see it, and it should have been clear after all that scheduler talk. And I think Babbage even suggested trying this once somewhere.

For mono, free memory is only checked when the script _isn't_ running. So, to get something interesting out of llGetFreeMemory, you need to force the script to yield. A timer will get a yield, so will llSleep.

In each example in this thread, things seem to come into line if I add a tiny llSleep before each llGetFreeMemory call. I'm using 0.03 because that's a little over a frame and ought to be enough to force a yield. The timers inserted in some scripts is likely causing the same yield-time reconciliation to happen.

Not in this thread so much, but yes, I've seen different scripts with identocal source code do different things with memory. I think Void has mentioned seeing that one too.


Yeah, Mono has that too. Early on, LL was only using it for the back-end library glue. Later we got this story about copying compiled assemblies around to save memory. That's exactly what the GAC accomplishes, so either scripts are now being added to that too, or LL duplicated the functionality.

so if it's waiting on the yield as you suggest, the random 28 byte flux we see back and forth is the difference between the get mem call being on the stack with an early return, and off and waiting for the return?

With bigger scripts the sleep is making some much larger differences go away too. It's enough to make me wonder if llGetFreeMemory under Mono can report anything better than "this is what we had at the beginning of the time slice". The rest may be fudging.

you'd think if that were the case then they'd build a yield into get free mem for mono =(

Good point.

I believe the smallest sleep you can actually get is 0.05. I suspect that any sleep yields the processor.

The .05 thing is a throttle for most events. I had been playing around with the llSleep thing, and the minimum time used is one frame (about .022, plus script overhead)

~.02 matches most of my rough testing for frame size