wso2wso2-api-manager
WSO2APIM v4.2: WebSocket connection timed out by GLOBAL_TIMEOUT config
Summary
We have WebSocket endpoint that is working fine on WSO2APIM v2.6 but can't get it to work with v4.2. Initial problem was the GLOBAL_TIMEOUT kicking in. We found a work.-around for that (see below). However, it now validates the bearer token for every message over the web socket so it dies after an hour! We need to be able to do long-lived web sockets like we did with v2.6.
Our sue of web sockets is as follows: the third party system connects to the web socket and we push event notifications out over it. We use this to support system-to-system integrations, so these socket connections can be open for days or even weeks at a time.
Current problem
In 4.2.0 it appears that the APIM is revalidating the authorization token for every message sent over the web socket (previously it only validated when you established the web socket connection). So, this means that after 1 hour the web socket connection dies as the token has expired.
Original Problem (Not Solved but Work-Around Found)
We have WebSocket endpoint that is working fine on WSO2APIM v2.6 but on WSO2APIM v4.2 it is timed out by GLOBAL_TIMEOUT config.
Once WebSocket connection is established it works properly for the next 5 minutes (our global timeout). After that WSO2APIM puts original WebSocket endpoint request into suspended state.
URL for calling endpoint looks like this wss://api-dev-carc.internal.com/notifications-feed/carcdev/v1. It is later mapped to backend endpoint wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1
I suspect that WSO2APIM is not aware that the original HTTP request is upgraded to WebSocket and as a result, APIM considers it a regular HTTP connection and applies GLOBAL_TIMEOUT config to it, and since no data is transferred over HTTP but over WebSocket original connection times out.
Is it an APIM bug or am I missing some config? Is it possible to specify which endpoints can be ignored by GLOBAL_TIMEOUT config?
deployment.toml
hostname = "api-dev-carc.internal.com"
base_path = "${carbon.protocol}://${carbon.host}:${carbon.management.port}"
server_role = "default"
[server.file_upload]
file_size_limit = "0"
[transport.https.properties]
proxyPort = 443
[super_admin]
username = "admin"
password = "$secret{admin_password}"
create_admin_account = true
[user_store]
type = "database_unique_id"
[identity_mgt.endpoint]
enable_self_signup_endpoint=false
[database.apim_db]
type = "mysql"
url = "jdbc:mysql://localhost:3306/apim_db"
username = "wso2"
password = "$secret{wso2am_db_password}"
driver = "com.mysql.cj.jdbc.Driver"
[database.shared_db]
type = "mysql"
url = "jdbc:mysql://localhost:3306/shared_db"
username = "wso2"
password = "$secret{wso2am_db_password}"
driver = "com.mysql.cj.jdbc.Driver"
[keystore.primary]
file_name = "wso2carbon.jks"
type = "JKS"
password = "$secret{keystore_password}"
alias = "wso2carbon"
key_password = "$secret{keystore_key_password}"
[keystore.internal]
file_name = "wso2carbon.jks"
type = "JKS"
password = "$secret{keystore_password}"
alias = "wso2carbon"
key_password = "$secret{keystore_key_password}"
[truststore]
type= "JKS"
file_name = "client-truststore.jks"
password= "$secret{client_truststore_password}"
[transport.wss]
sender.enable = true
sender.parameters.ws.outflow.dispatch.sequence = "outflowDispatchSeq"
sender.parameters.ws.outflow.dispatch.fault.sequence = "outflowFaultSeq"
sender.trust_store.location = "/opt/wso2am/wso2am-4.2.0/repository/resources/security/client-truststore.jks"
sender.trust_store.password = "wso2carbon"
[[apim.gateway.environment]]
name = "Default"
type = "hybrid"
provider = "wso2"
display_in_api_console = true
description = "This is a hybrid gateway that handles both production and sandbox token traffic."
show_as_token_endpoint_url = true
service_url = "https://api-dev-carc.internal.com:${mgt.transport.https.port}/services/"
username= "${admin.username}"
password= "${admin.password}"
ws_endpoint = "ws://api-dev-carc.internal.com:9099"
wss_endpoint = "wss://api-dev-carc.internal.com:8099"
http_endpoint = "http://api-dev-carc.internal.com"
https_endpoint = "https://api-dev-carc.internal.com"
websub_event_receiver_http_endpoint = "http://api-dev-carc.internal.com:9021"
websub_event_receiver_https_endpoint = "https://api-dev-carc.internal.com:8021"
[apim.sync_runtime_artifacts.gateway]
gateway_labels =["Default"]
[synapse_properties]
'synapse.global_timeout_interval'=300000
[passthru_http]
'http.socket.timeout'=360000
[apim.cache.resource]
enable = false
[apim.cache.jwt_claim]
enable = false
[apim.analytics]
enable = false
auth_token = ""
[apim.key_manager]
enable_apikey_subscription_validation = true
[apim.jwt]
enable = true
encoding = "base64" # base64,base64url
claim_dialect = "https://example.com/claims"
convert_dialect = true
header = "X-JWT-Assertion"
signing_algorithm = "NONE"
enable_user_claims = true
claims_extractor_impl = "org.wso2.carbon.apimgt.impl.token.DefaultClaimsRetriever"
[apim.jwt.gateway_generator]
impl = "com.api.gateway.JwtTokenGenerator"
[apim.devportal]
url = "https://api-dev-carc.internal.com/devportal"
display_url = true
[apim.cors]
allow_origins = "*"
allow_methods = ["GET","PUT","POST","DELETE","PATCH","OPTIONS"]
allow_headers = ["authorization","Access-Control-Allow-Origin","Content-Type","SOAPAction","apikey","Internal-Key"]
allow_credentials = false
[[event_handler]]
name="userPostSelfRegistration"
subscriptions=["POST_ADD_USER"]
[service_provider]
sp_name_regex = "^[\\sa-zA-Z0-9._-]*$"
[database.local]
type = "mysql"
url = "jdbc:mysql://localhost:3306/local_db"
username = "wso2"
password = "WPuufTdCgCKojVZ"
driver = "com.mysql.cj.jdbc.Driver"
[[event_listener]]
id = "token_revocation"
type = "org.wso2.carbon.identity.core.handler.AbstractIdentityHandler"
name = "org.wso2.is.notification.ApimOauthEventInterceptor"
order = 1
[event_listener.properties]
notification_endpoint = "https://api-dev-carc.internal.com/internal/data/v1/notify"
username = "${admin.username}"
password = "${admin.password}"
'header.X-WSO2-KEY-MANAGER' = "default"
[oauth.grant_type.token_exchange]
enable = true
allow_refresh_tokens = true
iat_validity_period = "1h"
[oauth.token_validation]
refresh_token_validity = 84600
[secrets]
admin_password = "foo"
wso2am_db_password = "foo"
keystore_password = "foo"
keystore_key_password = "foo"
client_truststore_password = "foo"
wso2Carbon.log
TID: [] [] [2023-06-21 12:52:27,002] INFO {org.apache.synapse.core.axis2.TimeoutHandler} - This engine will expire all callbacks after GLOBAL_TIMEOUT: 300 seconds, irrespective of the timeout action, after the specified or optional timeout
TID: [] [] [2023-06-21 12:57:42,008] WARN {org.apache.synapse.core.axis2.TimeoutHandler} - Expiring message ID : urn:uuid:07dfae83-2104-448c-b255-2d52b9394d8e; dropping message after GLOBAL_TIMEOUT of : 300 seconds for Endpoint [EventNotificationFeed-carcdev--vv1_APIproductionEndpoint], URI : wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1, Received through API : EventNotificationFeed-carcdev:vv1Correlation ID : 134735f2-272d-4c0a-89ca-05dfb9becb0e
TID: [] [] [2023-06-21 12:57:42,012] INFO {org.apache.synapse.endpoints.EndpointContext} - Endpoint : EventNotificationFeed-carcdev--vv1_APIproductionEndpoint with address wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1 has been marked for SUSPENSION, but no further retries remain. Thus it will be SUSPENDED.
TID: [] [] [2023-06-21 12:57:42,012] WARN {org.apache.synapse.endpoints.EndpointContext} - Suspending endpoint : EventNotificationFeed-carcdev--vv1_APIproductionEndpoint with address wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1 - current suspend duration is : 30000ms - Next retry after : Wed Jun 21 12:58:12 EEST 2023
TID: [] [] [2023-06-21 12:57:42,014] INFO {org.apache.synapse.mediators.builtin.LogMediator} - {api:EventNotificationFeed-carcdev:vv1} STATUS = Executing default 'fault' sequence, ERROR_CODE = 101504, ERROR_MESSAGE = Send timeout
TID: [] [] [2023-06-21 12:57:42,048] ERROR {org.apache.synapse.mediators.base.SequenceMediator} - {api:EventNotificationFeed-carcdev:vv1} refCnt: 0, decrement: 1 io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
at io.netty.util.internal.ReferenceCountUpdater.toLiveRealRefCnt(ReferenceCountUpdater.java:83)
at io.netty.util.internal.ReferenceCountUpdater.release(ReferenceCountUpdater.java:147)
at io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:101)
at io.netty.buffer.DefaultByteBufHolder.release(DefaultByteBufHolder.java:111)
at io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:90)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.handleSendBack(InboundWebsocketResponseSender.java:334)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.sendBack(InboundWebsocketResponseSender.java:225)
at org.apache.synapse.core.axis2.Axis2Sender.sendBack(Axis2Sender.java:209)
at org.apache.synapse.core.axis2.Axis2SynapseEnvironment.send(Axis2SynapseEnvironment.java:574)
at org.apache.synapse.mediators.builtin.SendMediator.mediate(SendMediator.java:123)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:110)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:72)
at org.apache.synapse.mediators.base.SequenceMediator.mediate(SequenceMediator.java:158)
at org.apache.synapse.mediators.MediatorFaultHandler.onFault(MediatorFaultHandler.java:96)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.endpoints.AbstractEndpoint.invokeNextFaultHandler(AbstractEndpoint.java:774)
at org.apache.synapse.endpoints.AbstractEndpoint.onFault(AbstractEndpoint.java:575)
at org.apache.synapse.endpoints.HTTPEndpoint.onFault(HTTPEndpoint.java:81)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.core.axis2.TimeoutHandler.processCallbacks(TimeoutHandler.java:210)
at org.apache.synapse.core.axis2.TimeoutHandler.run(TimeoutHandler.java:92)
at java.base/java.util.TimerThread.mainLoop(Timer.java:556)
at java.base/java.util.TimerThread.run(Timer.java:506)
TID: [] [] [2023-06-21 12:57:42,048] ERROR {API_LOGGER.EventNotificationFeed-carcdev} - refCnt: 0, decrement: 1 io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
at io.netty.util.internal.ReferenceCountUpdater.toLiveRealRefCnt(ReferenceCountUpdater.java:83)
at io.netty.util.internal.ReferenceCountUpdater.release(ReferenceCountUpdater.java:147)
at io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:101)
at io.netty.buffer.DefaultByteBufHolder.release(DefaultByteBufHolder.java:111)
at io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:90)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.handleSendBack(InboundWebsocketResponseSender.java:334)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.sendBack(InboundWebsocketResponseSender.java:225)
at org.apache.synapse.core.axis2.Axis2Sender.sendBack(Axis2Sender.java:209)
at org.apache.synapse.core.axis2.Axis2SynapseEnvironment.send(Axis2SynapseEnvironment.java:574)
at org.apache.synapse.mediators.builtin.SendMediator.mediate(SendMediator.java:123)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:110)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:72)
at org.apache.synapse.mediators.base.SequenceMediator.mediate(SequenceMediator.java:158)
at org.apache.synapse.mediators.MediatorFaultHandler.onFault(MediatorFaultHandler.java:96)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.endpoints.AbstractEndpoint.invokeNextFaultHandler(AbstractEndpoint.java:774)
at org.apache.synapse.endpoints.AbstractEndpoint.onFault(AbstractEndpoint.java:575)
at org.apache.synapse.endpoints.HTTPEndpoint.onFault(HTTPEndpoint.java:81)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.core.axis2.TimeoutHandler.processCallbacks(TimeoutHandler.java:210)
at org.apache.synapse.core.axis2.TimeoutHandler.run(TimeoutHandler.java:92)
at java.base/java.util.TimerThread.mainLoop(Timer.java:556)
at java.base/java.util.TimerThread.run(Timer.java:506)
TID: [] [] [2023-06-21 12:57:42,048] INFO {org.apache.synapse.mediators.builtin.LogMediator} - {api:EventNotificationFeed-carcdev:vv1} STATUS = Executing default 'fault' sequence, ERROR_CODE = 101504, ERROR_MESSAGE = Send timeout
TID: [] [] [2023-06-21 12:57:42,062] ERROR {org.apache.synapse.mediators.base.SequenceMediator} - {api:EventNotificationFeed-carcdev:vv1} refCnt: 0, decrement: 1 io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
at io.netty.util.internal.ReferenceCountUpdater.toLiveRealRefCnt(ReferenceCountUpdater.java:83)
at io.netty.util.internal.ReferenceCountUpdater.release(ReferenceCountUpdater.java:147)
at io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:101)
at io.netty.buffer.DefaultByteBufHolder.release(DefaultByteBufHolder.java:111)
at io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:90)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.handleSendBack(InboundWebsocketResponseSender.java:334)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.sendBack(InboundWebsocketResponseSender.java:225)
at org.apache.synapse.core.axis2.Axis2Sender.sendBack(Axis2Sender.java:209)
at org.apache.synapse.core.axis2.Axis2SynapseEnvironment.send(Axis2SynapseEnvironment.java:574)
at org.apache.synapse.mediators.builtin.SendMediator.mediate(SendMediator.java:123)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:110)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:72)
at org.apache.synapse.mediators.base.SequenceMediator.mediate(SequenceMediator.java:158)
at org.apache.synapse.mediators.MediatorFaultHandler.onFault(MediatorFaultHandler.java:96)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:65)
at org.apache.synapse.endpoints.AbstractEndpoint.invokeNextFaultHandler(AbstractEndpoint.java:774)
at org.apache.synapse.endpoints.AbstractEndpoint.onFault(AbstractEndpoint.java:575)
at org.apache.synapse.endpoints.HTTPEndpoint.onFault(HTTPEndpoint.java:81)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.core.axis2.TimeoutHandler.processCallbacks(TimeoutHandler.java:210)
at org.apache.synapse.core.axis2.TimeoutHandler.run(TimeoutHandler.java:92)
at java.base/java.util.TimerThread.mainLoop(Timer.java:556)
at java.base/java.util.TimerThread.run(Timer.java:506)
TID: [] [] [2023-06-21 12:57:42,062] ERROR {API_LOGGER.EventNotificationFeed-carcdev} - refCnt: 0, decrement: 1 io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
at io.netty.util.internal.ReferenceCountUpdater.toLiveRealRefCnt(ReferenceCountUpdater.java:83)
at io.netty.util.internal.ReferenceCountUpdater.release(ReferenceCountUpdater.java:147)
at io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:101)
at io.netty.buffer.DefaultByteBufHolder.release(DefaultByteBufHolder.java:111)
at io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:90)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.handleSendBack(InboundWebsocketResponseSender.java:334)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.sendBack(InboundWebsocketResponseSender.java:225)
at org.apache.synapse.core.axis2.Axis2Sender.sendBack(Axis2Sender.java:209)
at org.apache.synapse.core.axis2.Axis2SynapseEnvironment.send(Axis2SynapseEnvironment.java:574)
at org.apache.synapse.mediators.builtin.SendMediator.mediate(SendMediator.java:123)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:110)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:72)
at org.apache.synapse.mediators.base.SequenceMediator.mediate(SequenceMediator.java:158)
at org.apache.synapse.mediators.MediatorFaultHandler.onFault(MediatorFaultHandler.java:96)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:65)
at org.apache.synapse.endpoints.AbstractEndpoint.invokeNextFaultHandler(AbstractEndpoint.java:774)
at org.apache.synapse.endpoints.AbstractEndpoint.onFault(AbstractEndpoint.java:575)
at org.apache.synapse.endpoints.HTTPEndpoint.onFault(HTTPEndpoint.java:81)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.core.axis2.TimeoutHandler.processCallbacks(TimeoutHandler.java:210)
at org.apache.synapse.core.axis2.TimeoutHandler.run(TimeoutHandler.java:92)
at java.base/java.util.TimerThread.mainLoop(Timer.java:556)
at java.base/java.util.TimerThread.run(Timer.java:506)
TID: [] [] [2023-06-21 12:57:42,062] WARN {org.apache.synapse.core.axis2.TimeoutHandler} - Expiring message ID : urn:uuid:df06c7df-cfd7-4067-ad2a-bf7d380e2dc4; dropping message after GLOBAL_TIMEOUT of : 300 seconds for Endpoint [EventNotificationFeed-carcdev--vv1_APIproductionEndpoint], URI : wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1, Received through API : EventNotificationFeed-carcdev:vv1Correlation ID : 4d9d9438-5bae-4080-86d2-b3fd2517ffb7
TID: [] [] [2023-06-21 12:57:42,063] INFO {org.apache.synapse.endpoints.EndpointContext} - Endpoint : EventNotificationFeed-carcdev--vv1_APIproductionEndpoint with address wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1 has been marked for SUSPENSION, but no further retries remain. Thus it will be SUSPENDED.
TID: [] [] [2023-06-21 12:57:42,063] WARN {org.apache.synapse.endpoints.EndpointContext} - Suspending endpoint : EventNotificationFeed-carcdev--vv1_APIproductionEndpoint with address wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1 - last suspend duration was : 30000ms and current suspend duration is : 30000ms - Next retry after : Wed Jun 21 12:58:12 EEST 2023
TID: [] [] [2023-06-21 12:57:42,063] INFO {org.apache.synapse.mediators.builtin.LogMediator} - {api:EventNotificationFeed-carcdev:vv1} STATUS = Executing default 'fault' sequence, ERROR_CODE = 101504, ERROR_MESSAGE = Send timeout
TID: [] [] [2023-06-21 12:57:42,064] WARN {org.apache.synapse.core.axis2.TimeoutHandler} - Expiring message ID : urn:uuid:115991f4-50a5-42c2-a43b-3a3a8ae7baaf; dropping message after GLOBAL_TIMEOUT of : 300 seconds for Endpoint [EventNotificationFeed-carcdev--vv1_APIproductionEndpoint], URI : wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1, Received through API : EventNotificationFeed-carcdev:vv1Correlation ID : 9f45207d-61b3-47c2-a2c3-43f21472e6f0
TID: [] [] [2023-06-21 12:57:42,065] INFO {org.apache.synapse.endpoints.EndpointContext} - Endpoint : EventNotificationFeed-carcdev--vv1_APIproductionEndpoint with address wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1 has been marked for SUSPENSION, but no further retries remain. Thus it will be SUSPENDED.
TID: [] [] [2023-06-21 12:57:42,065] WARN {org.apache.synapse.endpoints.EndpointContext} - Suspending endpoint : EventNotificationFeed-carcdev--vv1_APIproductionEndpoint with address wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1 - last suspend duration was : 30000ms and current suspend duration is : 30000ms - Next retry after : Wed Jun 21 12:58:12 EEST 2023
TID: [] [] [2023-06-21 12:57:42,065] INFO {org.apache.synapse.mediators.builtin.LogMediator} - {api:EventNotificationFeed-carcdev:vv1} STATUS = Executing default 'fault' sequence, ERROR_CODE = 101504, ERROR_MESSAGE = Send timeout
TID: [] [] [2023-06-21 12:57:42,077] ERROR {org.apache.synapse.mediators.base.SequenceMediator} - {api:EventNotificationFeed-carcdev:vv1} refCnt: 0, decrement: 1 io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
at io.netty.util.internal.ReferenceCountUpdater.toLiveRealRefCnt(ReferenceCountUpdater.java:83)
at io.netty.util.internal.ReferenceCountUpdater.release(ReferenceCountUpdater.java:147)
at io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:101)
at io.netty.buffer.DefaultByteBufHolder.release(DefaultByteBufHolder.java:111)
at io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:90)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.handleSendBack(InboundWebsocketResponseSender.java:334)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.sendBack(InboundWebsocketResponseSender.java:225)
at org.apache.synapse.core.axis2.Axis2Sender.sendBack(Axis2Sender.java:209)
at org.apache.synapse.core.axis2.Axis2SynapseEnvironment.send(Axis2SynapseEnvironment.java:574)
at org.apache.synapse.mediators.builtin.SendMediator.mediate(SendMediator.java:123)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:110)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:72)
at org.apache.synapse.mediators.base.SequenceMediator.mediate(SequenceMediator.java:158)
at org.apache.synapse.mediators.MediatorFaultHandler.onFault(MediatorFaultHandler.java:96)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.endpoints.AbstractEndpoint.invokeNextFaultHandler(AbstractEndpoint.java:774)
at org.apache.synapse.endpoints.AbstractEndpoint.onFault(AbstractEndpoint.java:575)
at org.apache.synapse.endpoints.HTTPEndpoint.onFault(HTTPEndpoint.java:81)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.core.axis2.TimeoutHandler.processCallbacks(TimeoutHandler.java:210)
at org.apache.synapse.core.axis2.TimeoutHandler.run(TimeoutHandler.java:92)
at java.base/java.util.TimerThread.mainLoop(Timer.java:556)
at java.base/java.util.TimerThread.run(Timer.java:506)
TID: [] [] [2023-06-21 12:57:42,077] ERROR {API_LOGGER.EventNotificationFeed-carcdev} - refCnt: 0, decrement: 1 io.netty.util.IllegalReferenceCountException: refCnt: 0, decrement: 1
at io.netty.util.internal.ReferenceCountUpdater.toLiveRealRefCnt(ReferenceCountUpdater.java:83)
at io.netty.util.internal.ReferenceCountUpdater.release(ReferenceCountUpdater.java:147)
at io.netty.buffer.AbstractReferenceCountedByteBuf.release(AbstractReferenceCountedByteBuf.java:101)
at io.netty.buffer.DefaultByteBufHolder.release(DefaultByteBufHolder.java:111)
at io.netty.util.ReferenceCountUtil.release(ReferenceCountUtil.java:90)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.handleSendBack(InboundWebsocketResponseSender.java:334)
at org.wso2.carbon.inbound.endpoint.protocol.websocket.InboundWebsocketResponseSender.sendBack(InboundWebsocketResponseSender.java:225)
at org.apache.synapse.core.axis2.Axis2Sender.sendBack(Axis2Sender.java:209)
at org.apache.synapse.core.axis2.Axis2SynapseEnvironment.send(Axis2SynapseEnvironment.java:574)
at org.apache.synapse.mediators.builtin.SendMediator.mediate(SendMediator.java:123)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:110)
at org.apache.synapse.mediators.AbstractListMediator.mediate(AbstractListMediator.java:72)
at org.apache.synapse.mediators.base.SequenceMediator.mediate(SequenceMediator.java:158)
at org.apache.synapse.mediators.MediatorFaultHandler.onFault(MediatorFaultHandler.java:96)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.endpoints.AbstractEndpoint.invokeNextFaultHandler(AbstractEndpoint.java:774)
at org.apache.synapse.endpoints.AbstractEndpoint.onFault(AbstractEndpoint.java:575)
at org.apache.synapse.endpoints.HTTPEndpoint.onFault(HTTPEndpoint.java:81)
at org.apache.synapse.FaultHandler.handleFault(FaultHandler.java:60)
at org.apache.synapse.core.axis2.TimeoutHandler.processCallbacks(TimeoutHandler.java:210)
at org.apache.synapse.core.axis2.TimeoutHandler.run(TimeoutHandler.java:92)
at java.base/java.util.TimerThread.mainLoop(Timer.java:556)
at java.base/java.util.TimerThread.run(Timer.java:506)
UPD
We turned off Endpoint suspension according to https://apim.docs.wso2.com/en/latest/design/endpoints/resiliency/prevent-api-suspension/#!
Additionally turned off "Endpoint Timeout State" and changed the Connection timeout action to "Discard message"
This is not an ideal solution. It still creates noise in logs:
TID: [] [] [2023-07-03 15:27:20,920] WARN {org.apache.synapse.core.axis2.TimeoutHandler} - Expiring message ID : urn:uuid:856eccfb-48e2-4612-a202-7d70d775af1e; dropping message after ENDPOINT_TIMEOUT of : 30 seconds for Endpoint [EventNotificationFeed-carcdev--vv1_APIproductionEndpoint], URI : wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1, Received through API : EventNotificationFeed-carcdev:vv1Correlation ID : d8d02263-aaef-4ba7-b476-1db5cb88b2fa
TID: [] [] [2023-07-03 15:27:20,921] INFO {org.apache.synapse.endpoints.HTTPEndpoint} - Ignoring fault handlers since the timeout action is set to DISCARD
TID: [] [] [2023-07-03 15:27:20,921] WARN {org.apache.synapse.core.axis2.TimeoutHandler} - Expiring message ID : urn:uuid:09709167-dc2f-48cc-8d4f-6c19ceb1ee21; dropping message after ENDPOINT_TIMEOUT of : 30 seconds for Endpoint [EventNotificationFeed-carcdev--vv1_APIproductionEndpoint], URI : wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1, Received through API : EventNotificationFeed-carcdev:vv1Correlation ID : 4eab3eff-a488-4dbd-b1be-b470dc2909e4
TID: [] [] [2023-07-03 15:27:20,922] INFO {org.apache.synapse.endpoints.HTTPEndpoint} - Ignoring fault handlers since the timeout action is set to DISCARD
TID: [] [] [2023-07-03 15:27:50,921] WARN {org.apache.synapse.core.axis2.TimeoutHandler} - Expiring message ID : urn:uuid:23e52b2d-c5ff-4269-bdf1-640c10391aaf; dropping message after ENDPOINT_TIMEOUT of : 30 seconds for Endpoint [EventNotificationFeed-carcdev--vv1_APIproductionEndpoint], URI : wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1, Received through API : EventNotificationFeed-carcdev:vv1Correlation ID : 70525761-b370-4508-95ef-afb6910c3037
TID: [] [] [2023-07-03 15:27:50,922] INFO {org.apache.synapse.endpoints.HTTPEndpoint} - Ignoring fault handlers since the timeout action is set to DISCARD
TID: [] [] [2023-07-03 15:27:50,922] WARN {org.apache.synapse.core.axis2.TimeoutHandler} - Expiring message ID : urn:uuid:9d46093c-9f32-46c5-9915-338f62a62ebd; dropping message after ENDPOINT_TIMEOUT of : 30 seconds for Endpoint [EventNotificationFeed-carcdev--vv1_APIproductionEndpoint], URI : wss://apisvc-dev-carc.internal.com:443/rest-api/v1/notifications/v1, Received through API : EventNotificationFeed-carcdev:vv1Correlation ID : d72b89fd-e50f-4c69-a025-01b4924ae594
TID: [] [] [2023-07-03 15:27:50,924] INFO {org.apache.synapse.endpoints.HTTPEndpoint} - Ignoring fault handlers since the timeout action is set to DISCARD
UPD 2: WSO2 automatically drops active WebSocket connection once Bearer token is expired:
TID: [] [] [2023-07-05 13:30:48,618] ERROR {org.wso2.carbon.apimgt.gateway.inbound.websocket.utils.InboundWebsocketProcessorUtil} - 4001 org.wso2.carbon.apimgt.gateway.handlers.security.APISecurityException: Invalid JWT token
at org.wso2.carbon.apimgt.gateway.handlers.security.jwt.JWTValidator.authenticateForWebSocket_aroundBody20(JWTValidator.java:491)
at org.wso2.carbon.apimgt.gateway.handlers.security.jwt.JWTValidator.authenticateForWebSocket(JWTValidator.java:1)
at org.wso2.carbon.apimgt.gateway.inbound.websocket.utils.InboundWebsocketProcessorUtil.authenticateToken_aroundBody22(InboundWebsocketProcessorUtil.java:461)
at org.wso2.carbon.apimgt.gateway.inbound.websocket.utils.InboundWebsocketProcessorUtil.authenticateToken(InboundWebsocketProcessorUtil.java:1)
at org.wso2.carbon.apimgt.gateway.inbound.websocket.utils.InboundWebsocketProcessorUtil.authenticateToken_aroundBody20(InboundWebsocketProcessorUtil.java:439)
at org.wso2.carbon.apimgt.gateway.inbound.websocket.utils.InboundWebsocketProcessorUtil.authenticateToken(InboundWebsocketProcessorUtil.java:1)
at org.wso2.carbon.apimgt.gateway.inbound.websocket.response.ResponseProcessor.handleResponse_aroundBody0(ResponseProcessor.java:47)
at org.wso2.carbon.apimgt.gateway.inbound.websocket.response.ResponseProcessor.handleResponse(ResponseProcessor.java:1)
at org.wso2.carbon.apimgt.gateway.inbound.websocket.InboundWebSocketProcessor.handleResponse_aroundBody4(InboundWebSocketProcessor.java:196)
Solution
Unfortunately we were not able to fix an issue with WebSockets on WSO2 side. So we're using something other than WSO2 for web sockets.
That WSO2 change to WebSockets was introduced here https://github.com/wso2/product-apim/issues/12413