wso2
Issue with Header Mediator in multi thread environment
Description: Header Mediator is not working as expected in multi threaded environments.
I built a flow which will be invoked concurrently my many users. I am setting a property called 'clientId'( unique identifier for each user) in header mediator and also in the message context(say a payload factory). In some rare scenario, I have observed that the clientId in header and payload factory are showing differently. After debugging further, I noticed that clientId in header mediator is coming from a different thread ( thread2) and clientId in payload factory is set from current thread( thread1). Say the current thread is thread1.
After extracting logs from thread2, clientId in header and payload factory in thread2 are set correctly (with value of thread2)
sample code where the issue is observed
<payloadFactory description="gl-detail payload" media-type="json">
<format>{ "clientId": $1, "sourceName": "$2","sourceId": "$3" }
</format>
<args>
<arg evaluator="xml" expression="get-property('clientId')"/>
<arg evaluator="xml" expression="get-property('sourceName')"/>
<arg evaluator="xml" expression="get-property('sourceId')"/>
</args>
</payloadFactory>
<header description="clientid" expression="get-property('clientId')" name="clientid" scope="transport"/>
<call blocking="true">
<endpoint key="gov:endpoints/UpdateSourceDetailEP.xml"/>
</call>
Version : WSO2 Micro Integrator 1.2
This use case is causing issues for us as the critical client level information is getting swapped in our production environment. I am referring to this link which says that header mediator is conditionally content aware and guessing this could be an issue. https://ei.docs.wso2.com/en/latest/micro-integrator/references/mediators/header-Mediator/
I couldn't find much help online trying to understand this issue. Kindly help us to fix this problem at the earliest.
Thanks in advance.
@Nirothipan Thanks for the response. Just want to provide more information on this issue. In trying to fix this issue, I replaced the header mediator with property mediator with scope=transport, check the sample code below
<payloadFactory description="gl-detail payload" media-type="json">
<format>{ "clientId": $1, "sourceName": "$2","sourceId": "$3" }
</format>
<args>
<arg evaluator="xml" expression="get-property('clientId')"/>
<arg evaluator="xml" expression="get-property('sourceName')"/>
<arg evaluator="xml" expression="get-property('sourceId')"/>
</args>
</payloadFactory>
<property description="clientid" expression="get-property('clientId')" name="clientid" scope="transport" type="STRING"/>
<call blocking="true">
<endpoint key="gov:endpoints/UpdateSourceDetailEP.xml"/>
</call>
But still the client id is getting swapped in the header from a different thread, when concurrent requests are made to this sequence. So now I am suspecting the issue could be with the call mediator or the endpoint mediator. After further debugging, I understood that the endpoint is common across all threads and is not specific to any thread. So, when concurrent requests come to this endpoint, not sure how it is behaving.
Please let me know if any further information is needed. @heysulo @Nirothipan
@sreenath-centime I couldn't get this issue recreated in both the latest version and the v1.2.0 of WSO2 Micro Integrator. Yet I'm still looking into this. Is it possible to use a Log/Validate Mediator right before the call Mediator just to make sure that the issue actually resides in the WSO2 Micro Integrator, and not the third-party endpoint?
@heysulo Thanks for the response. We are actually using a log mediator before the call mediator, to print the client id value in transport context and default context. Below are the logs..
<payloadFactory description="gl-detail payload" media-type="json">
<format>{ "clientId": $1, "sourceName": "$2","sourceId": "$3" }
</format>
<args>
<arg evaluator="xml" expression="get-property('clientId')"/>
<arg evaluator="xml" expression="get-property('sourceName')"/>
<arg evaluator="xml" expression="get-property('sourceId')"/>
</args>
</payloadFactory>
<property description="clientid" expression="get-property('clientId')" name="clientid" scope="transport" type="STRING"/>
<log level="custom">
<property expression="$trp:clientid" name="header clientid"/>
<property expression="$ctx:clientId" name="ctx clientid"/>
</log>
<call blocking="true">
<endpoint key="gov:endpoints/UpdateSourceDetailEP.xml"/>
</call>
As you can see I am printing 'clientid' from header and 'clientId' from default context. Both values always print the same values. One observation is in transport context, I am setting small case 'clientid' and in default context, I am setting camelCase 'clientId'. Could this be a problem?
Though the values are printed same all the time, I am suspecting once the message reaches call mediator and subsequently the endpoint mediator - because both are content unaware and endpoint is not thread specific - Is there a possibility that the values are getting swapped between threads after the message reaches call mediator or endpoint mediator??
We are frequently seeing this issue in our production environment where many clients execute the above code in parallel. But unable to reproduce on lower envs. We are still trying to evaluate the possibility of the issue being at the external service which is exposing the api used in the endpoint mediator, (external service is a simple spring boot micro service).
Let me know if you need any further information to debug this issue. Thanks.
@sreenath-centime the character case doesn't seem to be a problem, I've used the same during my attempts to recreate the issue. This is the flow I used
<?xml version="1.0" encoding="UTF-8"?>
<api context="/delayed" name="NodeAPI" xmlns="http://ws.apache.org/ns/synapse">
<resource methods="POST" url-mapping="/">
<inSequence>
<log description="Logger" level="custom">
<property expression="json-eval($.clientId)" name="BodyClientIdValue"/>
</log>
<property description="clientId" expression="json-eval($.clientId)" name="clientId" scope="default" type="INTEGER"/>
<log level="custom">
<property expression="get-property('clientId')" name="PropertyClientIdValue"/>
</log>
<payloadFactory media-type="json">
<format>{"clientId": $1}</format>
<args>
<arg evaluator="xml" expression="get-property('clientId')"/>
</args>
</payloadFactory>
<property description="clientId" expression="get-property('clientId')" name="clientid" scope="transport" type="STRING"/>
<log level="full"/>
<call blocking="true">
<endpoint key="NodeBackend"/>
</call>
<respond/>
</inSequence>
<outSequence/>
<faultSequence/>
</resource>
</api>
The endpoint I'm using is a NodeJS endpoint and it verifies that both client ID values from the header and body are the same. I've added a 1s delay just because we are using a blocking mode in the call mediator. In blocking mode, the underlying worker thread gets blocked and waits for the response after sending the request to the endpoint.
Node Backend
app.post('/delayed', (req, res) => {
let reqSeqID = allocateSeqID();
setTimeout(() => {
const headerId = req.header('clientid');
const bodyId = req.body.clientId;
if (headerId != bodyId)
{
console.log(`Request mismatch H:${headerId} B:${bodyId}`);
}
else
{
console.log(`Request match H:${headerId} B:${bodyId}`);
}
res.setHeader('Content-Type', 'application/json')
res.send({
responseId: reqSeqID,
headerClientId: headerId,
bodyClientId: bodyId
});
dispatch(reqSeqID);
}, 1000);
})
HTTP request spamming script
import requests
import threading
from multiprocessing import Process
id = 0
def thread_function(name):
global id
while True:
id += 1
headers = {
'clientId': str(id)
}
json_data = {
'clientId': str(id)
}
response = requests.post('http://localhost:8290/delayed/', headers=headers, json=json_data)
if __name__ == "__main__":
for i in range(1250):
print("Thread", i, "spawned")
x = threading.Thread(target=thread_function, args=(1,))
x.start()
@heysulo Thanks a lot for looking into this issue, We are also trying to reproduce this issue but unable to do so, but it is happening very frequently in our production env.
We will get back to you if we are able to reproduce this at our end. Thanks