Cache pulls non-deterministically return a live object ref to some "other" object

[MordantWastrel]

David @ inLeague was investigating some strange behavior where redis cache gets were producing objects we'd pulled on previous requests, modified in Lucee, but then not written back to the cache, and he found the following. This occurs either with direct redis interaction or with Cachebox.

It seems pulling from cache will non-deterministically return a live object ref to some object elsewhere in the program:

function directlyUseRedis() {
    var someObj = {value: 42}
    var someKey = "someKey-devdevdev-justredis"

    cachePut(
        someKey,
        someObj,
        createTimeSpan( 9, 9, 9, 9 ),
        createTimeSpan( 9, 9, 9, 9 ),
        "default"
    )

    var x = cacheGet(cacheName="default", id=someKey);

    // sometimes the cached source and cached origin object are exactly the same, maybe 33% of the time
    return {isSame_redis: x === someObj}
}

function useCachebox() {
    var someObj = {value: 42}
    var someKey = "someKey-devdevdev-cbox"
    var objectCache = getInstance("cachebox:object")
    objectCache.set( someKey, someObj );

    var x = objectCache.get( someKey );

    return {isSame_cachebox: x === someObj};
}

function doit() {
    redis = []
    cachebox = []
    for (i = 0; i < 10; ++i) {
        cachebox.append(useCachebox());
        redis.append(directlyUseRedis());
    }

    writedump(redis);
    writedump(cachebox)
}

doit();

abort;

Redis driver: 3.0.0.48 Lucee: 5.3.10.120

We did not notice this until we upgraded from 3.0.0.47, but the specific kind of interaction going on here doesn't happen a ton with us so that may be a red herring.

[davidAtInleague]

It seems like the "live ref" is returned only prior to the object being actually persisted to redis. So there is a bit of a race between cache-put/cache-get, and can result in a request to write V inadvertently writing some modified version of V.

I think our scenario went something like the following:

redis thread:
a) ...
b) ...
c) ...
d) ...
e) notified
f) write (K,V), it contains the mutations from thread1 or thread2

Thread1:
a) try lock L
b) get L, cachePut(K, V)
c) release L
d) mutate V (live ref to value pending write in cache)
e) all done

Thread 2:
a) try lock L
b) can't get L, wait for owner of L to release ("cool, someone else put it in cache, I'll use that")
c) V = cacheGet(K) (live ref to V, same as on Thread1)
d) mutate V
e) all done

Some reproduction:

function foo() {
    var someKey ="someKey-devredis"
    var someObj = {value: 42}
    cachePut(
        someKey,
        someObj,
        createTimeSpan( 9, 9, 9, 9 ),
        createTimeSpan( 9, 9, 9, 9 ),
        "default"
    )

    // sleep(20); // a sleep here will force the redis thread to win (and the value-written-to-redis will be 42)

    // if the value hasn't been written to redis yet, this live ref will alter the value that is waiting to be written
    // if the value has been written to redis, it appears this is not a live ref to the original object
    cacheGet(someKey).value = 999;

    // 42 or 999, depending on who won the race
    //
    // often, it is enough to run this file a few times to skew it to most-always 999 (though the prefereable value is 42)
    // (probably this gets the JIT warmed up, and then the race is more easily won by "this thread" rather
    // than the redis driver thread waiting on tokenAddToNear.wait())
    writedump(cacheGet(someKey) === someObj); // here the objects may or may not be identical
    writedump(cacheGet(someKey).value)

    sleep(100)
    cacheGet(someKey).value = 1000;
    writedump(cacheGet(someKey).value) // race is almost certainly over after 100ms, this is always the value that won the race earlier
    writedump(cacheGet(someKey) === someObj); // here the objects are almost certainly not identical after a 100ms allowance for the redis thread to do its work
}