EPP crashing during scale test

[kfswain]

Running scale testing for the EPP

QPS: 10k
length of prompt: 10k char
16 sim server backends

The EPP repeatedly hit fatal crashes a dump from the logs of one of the crashed pods shows

logs.txt

[kfswain]

Looks to be a prefix cache plugin issue, will continue to RCA and take a look into fixes

[kfswain]

Looking at the logs, the requestID is always set to "".

And the plugin state uses the request ID as the key:

gateway-api-inference-extension/pkg/epp/plugins/plugin_state.go

Line 63 in 229c122

s.requestToLastAccessTime.Store(requestID, time.Now())

there is a sync map for the outer plugin state, but keyed on the requestID, so its essentially all contending for a single entry.

Sync should still not have lock contention.. will continue to dig

[kfswain]

This line:

gateway-api-inference-extension/pkg/epp/scheduling/framework/plugins/multi/prefix/indexer.go

Line 66 in 229c122

for _, hash := range hashes {

Is also a potential issue, we are adding to the map without locks, this could very likely cause the fatal error: concurrent map writes Will try rerunning without the prefix plugin to see if that fixes

[nirrozenbaum]

cc: @vMaroon @kfirtoledo please have a look also if you have free cycles

[nirrozenbaum]

found the bug. the following code is in the PluginState, used by the Prefix plugin:

gateway-api-inference-extension/pkg/epp/plugins/plugin_state.go

Lines 78 to 91 in dc82925

	func (s *PluginState) Write(requestID string, key StateKey, val StateData) {
	s.requestToLastAccessTime.Store(requestID, time.Now())
	var stateData map[StateKey]StateData
	stateMap, ok := s.storage.Load(requestID)
	if ok {
	stateData = stateMap.(map[StateKey]StateData)
	} else {
	stateData = map[StateKey]StateData{}
	}
	stateData[key] = val
	s.storage.Store(requestID, stateData)
	}

since RequestID is always "", different requests are getting the same stateMap in line 81, and then try to write concurrently different values to the same map in line 88.

RequestID should always be set. I will push a fix.

[nirrozenbaum]

opened a PR #1490 with a fix.
I'd be happy to get an update after repeating the test with this fix that it's not reproducible.

[nirrozenbaum]

This line:

gateway-api-inference-extension/pkg/epp/scheduling/framework/plugins/multi/prefix/indexer.go

Line 66 in 229c122

for _, hash := range hashes {
Is also a potential issue, we are adding to the map without locks, this could very likely cause the fatal error: concurrent map writes Will try rerunning without the prefix plugin to see if that fixes

This looks like yet another bug. not sure what we really save here with the unlocking before the for loop and locking again right after. for loop should be very fast that this seems like a premature optimization. It's a different bug fix than #1490.
will push in another PR

[nirrozenbaum]

This line:
gateway-api-inference-extension/pkg/epp/scheduling/framework/plugins/multi/prefix/indexer.go
Line 66 in 229c122
for _, hash := range hashes {
Is also a potential issue, we are adding to the map without locks, this could very likely cause the fatal error: concurrent map writes Will try rerunning without the prefix plugin to see if that fixes

This looks like yet another bug. not sure what we really save here with the unlocking before the for loop and locking again right after. for loop should be very fast that this seems like a premature optimization. It's a different bug fix than #1490. will push in another PR

after further analysis, this function seems to be fine. cache.Add uses internally a lock to protect the LRU cache per pod.
not only that no need to lock it, if we lock we hit deadlock (was trying to play with that).
current implementation of this function seems correct, so hopefully the fix in #1490 solves the probelm.

[nirrozenbaum]

@kfswain out of curiosity, can you provide details about the gateway you were using?
I assume GKE?
I remember reading envoy always generates the X-Request-Id header which is kind of a standard. does GKE generate that header? the fix handles the case it doesn't, but asking for my understanding.

[kfswain]

found the bug. the following code is in the PluginState, used by the Prefix plugin:

gateway-api-inference-extension/pkg/epp/plugins/plugin_state.go

Lines 78 to 91 in dc82925

func (s *PluginState) Write(requestID string, key StateKey, val StateData) {
s.requestToLastAccessTime.Store(requestID, time.Now())
var stateData map[StateKey]StateData
stateMap, ok := s.storage.Load(requestID)
if ok {
stateData = stateMap.(map[StateKey]StateData)
} else {
stateData = map[StateKey]StateData{}
}

stateData[key] = val

s.storage.Store(requestID, stateData)
}
since RequestID is always "", different requests are getting the same stateMap in line 81, and then try to write concurrently different values to the same map in line 88.

RequestID should always be set. I will push a fix.

All these use sync.Maps under the hood, so even with the same key I think there shouldnt be concurrent writes... Even if the value is yet another map