Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
MordantWastrel opened this issue Mar 2, 2023 · 1 comment · May be fixed by #16
Open

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

MordantWastrel opened this issue Mar 2, 2023 · 1 comment · May be fixed by #16

Comments

@MordantWastrel
Copy link

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
Copy link

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
}

zspitzer added a commit that referenced this issue Mar 3, 2023
davidAtInleague added a commit to davidAtInleague/extension-redis that referenced this issue Apr 9, 2023
With goal being not sharing live object refs to the underlying
"to-be-cached" objects across NearCacheEntry objects

resolves lucee#13
davidAtInleague added a commit to davidAtInleague/extension-redis that referenced this issue Nov 30, 2023
With goal being not sharing live object refs to the underlying
"to-be-cached" objects across NearCacheEntry objects

fixes test introduced in prior commit

resolves lucee#13
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
2 participants