Okay so now I’ve been looking at the code on GitHub and I have a theory. Now i’ve not used Go before so I’m unaware of any subtleties around it’s threading but:
Wherever you deal with the nonce you’re using ServiceNonceMutex.Lock() and ServiceNonceMutex.UnLock()
However during a HTTP request you’re doing it twice - once to read the nonce and once to set it. Here’s an abbreviated exert from:
ServiceNonceMutex.Lock()
newRequest.Header.Add("x-tyk-nonce", ServiceNonce)
ServiceNonceMutex.Unlock()
....
ServiceNonceMutex.Lock()
ServiceNonce = thisVal.Nonce
log.Debug("Hearbeat Finished: Nonce Set: ", ServiceNonce)
ServiceNonceMutex.Unlock()
However at the same time you’re also doing this in the policy load:
Exert:
ServiceNonceMutex.Lock()
newRequest.Header.Add("x-tyk-nonce", ServiceNonce)
ServiceNonceMutex.Unlock()
....
ServiceNonceMutex.Lock()
ServiceNonce = thisList.Nonce
log.Debug("Loading Policies Finished: Nonce Set: ", ServiceNonce)
ServiceNonceMutex.Unlock()
So talking about Threads we have 2, one running the heartbeat and the other loading the policies:
Thread 2, Lock mutex
Thread 2, Retreive NONCE-1
Thread 2, Unlock mutex
Thread 1, Lock mutex.
Thread 1, Retreive NONCE-1
Thread 1, Unlock mutex
Thread 1, HTTP CALL
Thread 1, Lock Mutex
Thread 1, Set NONCE-2
Thread 1, Unlock Mutex
Thread 2, HTTP CALL
Thread 2, ERROR
The solution I think here, although it has other potential knock on issues, is to lock the mutex for the entirety of the HTTP call. This would ensure that the nonce is used and updated in one transaction if it is indeed updated after every http transaction.
EDIT. I think the actual threading issue is probably between the API Loading and the Heartbeat which then has a knock on effect on the policy rather than it being the policy loading thread at fault. I can’t seem to see how, looking at the code, the Heartbeat and API Loading could operate with the mutex to produce the log output above.
Thoughts from the Tyk development team?
Cheers,
Richard