Ravi N.
Reputation: 91
WSO2 API Manager returns http 500 error code
Going thru the WSO2 API Manager logs, we noticed few occurrences where calls returned as HTTP 500 error and successful on subsequent retry by client. This does not happen all the time (at about 5% rate). And all these incidents are from the same source IP. Looking further, these calls that fails with HTTP 500, never get send to back-end endpoint for actual processing - Therefore, these calls are failed by WSO2 API Manager itself.
We have verified the CPU, Memory of WSO2 are at normal working level. Our WSO2 APIM environment is with no authorization token enabled (simple pass thru with throttle) - hence this can be counted out.
From log, the error 500 is returned almost immediate and retry typically happens within 200ms. And all these errors (about 49) happens within same hour.
We also not able to verify the exact error message as API calls is from one of our client.
Appreciate if you could list down all possibilities as why WSO2 may returned HTTP 500 in this case. Otherwise, how we able to investigate the scenario further. Thanks.
Here are relevant logs
WSO2 APIM AWS ELB access logs
$ grep 'fromIndex=394501&toIndex=395000' *.log WSO2APIM_ELBACESS.log:2016-12-06T08:37:37.905822Z wso2-oss-server x.x.x.x:63598 x.x.x.98:8280 0.000042 0.001862 0.000023 500 500 0 293 "GET https://wso2apimanager:443/rest/request?view=full&fromIndex=394501&toIndex=395000&lastModifiedFrom=2016-12-05%2000%3A00%3A00 HTTP/1.1" "RestSharp/x.x.x.x" ECDHE-RSA-AES128-SHA TLSv1 WSO2APIM_ELBACESS.log:2016-12-06T08:37:38.102539Z wso2-oss-server x.x.x.x:63598 x.x.x.120:8280 0.000041 0.035397 0.000025 200 200 0 33 "GET https://wso2apimanager:443/rest/request?view=full&fromIndex=394501&toIndex=395000&lastModifiedFrom=2016-12-05%2000%3A00%3A00 HTTP/1.1" "RestSharp/x.x.x.x" ECDHE-RSA-AES128-SHA TLSv1WSO2 APIM http access log
$ grep 'fromIndex=394501&toIndex=395000' *.log http_access_2016-12-06.log_m1:x.x.x.x x.x.x.140 - - [06/Dec/2016:08:37:37 +0000] "GET /rest/request?view=full&fromIndex=394501&toIndex=395000&lastModifiedFrom=2016-12-05%2000%3A00%3A00 HTTP/1.1" - - "-" "RestSharp/x.x.x.x" http_access_2016-12-06.log_m1:x.x.x.x x.x.x.72 - - [06/Dec/2016:08:37:37 +0000] "GET /rest/request?view=full&fromIndex=394501&toIndex=395000&lastModifiedFrom=2016-12-05%2000%3A00%3A00 HTTP/1.1" - - "-" "Synapse-PT-HttpComponents-NIO" http_access_2016-12-06.log_m2:x.x.x.x x.x.x.140 - - [06/Dec/2016:08:37:37 +0000] "GET /rest/request?view=full&fromIndex=394501&toIndex=395000&lastModifiedFrom=2016-12-05%2000%3A00%3A00 HTTP/1.1" - - "-" "RestSharp/x.x.x.x"Back-end AWS ELB access log
$ grep 'fromIndex=394501&toIndex=395000' *.log BACKEND_ELBACCESS.log:2016-12-06T08:37:38.104641Z vpc-connect-api x.x.x.120:46946 x.x.x.23:80 0.000045 0.032717 0.000022 200 200 0 33 "GET http://backendserver:80/rest/request?view=full&fromIndex=394501&toIndex=395000&lastModifiedFrom=2016-12-05%2000%3A00%3A00 HTTP/1.1" "Synapse-PT-HttpComponents-NIO" - -WSO2 API Manager 1 (wso2carbon.log)
TID: [-1234] [] [2016-12-06 08:34:47,427] INFO {org.wso2.carbon.databridge.core.DataBridge} - user admin connected {org.wso2.carbon.databridge.core.DataBridge} TID: [-1234] [] [2016-12-06 08:35:18,069] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1] [] [2016-12-06 08:35:47,850] INFO {org.wso2.andes.kernel.AndesRecoveryTask} - Running DB sync task. {org.wso2.andes.kernel.AndesRecoveryTask} TID: [-1] [] [2016-12-06 08:37:13,485] WARN {org.apache.synapse.transport.passthru.TargetHandler} - http-outgoing-16702: Connection time out while in state: REQUEST_DONE {org.apache.synapse.transport.passthru.TargetHandler} TID: [-1234] [] [2016-12-06 08:37:13,486] WARN {org.apache.synapse.endpoints.EndpointContext} - Endpoint : admin--XXX_APIproductionEndpoint_28 will be marked SUSPENDED as it failed {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:37:13,486] WARN {org.apache.synapse.endpoints.EndpointContext} - Suspending endpoint : admin--XXX_APIproductionEndpoint_28 - current suspend duration is : 30000ms - Next retry after : Tue Dec 06 08:37:43 UTC 2016 {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:37:13,486] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 101507, ERROR_MESSAGE = Error in Sender {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1] [] [2016-12-06 08:37:13,487] WARN {org.apache.synapse.transport.passthru.SourceHandler} - Connection time out after request is read: http-incoming-566702 {org.apache.synapse.transport.passthru.SourceHandler} TID: [-1234] [] [2016-12-06 08:37:13,961] INFO {org.apache.synapse.endpoints.EndpointContext} - Endpoint : admin--XXX_APIproductionEndpoint_28 currently SUSPENDED will now be marked active since it processed its last message {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:37:18,342] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:39:18,007] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:40:17,933] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:41:17,725] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:43:17,811] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:45:17,892] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:47:18,363] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1] [] [2016-12-06 08:50:47,850] INFO {org.wso2.andes.kernel.AndesRecoveryTask} - Running DB sync task. {org.wso2.andes.kernel.AndesRecoveryTask} TID: [-1234] [] [2016-12-06 08:51:17,864] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:53:17,753] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:55:18,025] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:57:18,333] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:59:17,949] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator}WSO2 API Manager 2 (wso2carbon.log)
TID: [-1234] [] [2016-12-06 08:34:54,620] INFO {org.wso2.carbon.databridge.core.DataBridge} - user admin connected {org.wso2.carbon.databridge.core.DataBridge} TID: [-1234] [] [2016-12-06 08:36:18,043] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1] [] [2016-12-06 08:37:13,674] WARN {org.apache.synapse.transport.passthru.TargetHandler} - http-outgoing-16760: Connection time out while in state: REQUEST_DONE {org.apache.synapse.transport.passthru.TargetHandler} TID: [-1234] [] [2016-12-06 08:37:13,692] WARN {org.apache.synapse.endpoints.EndpointContext} - Endpoint : admin--XXX_APIproductionEndpoint_28 will be marked SUSPENDED as it failed {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:37:13,693] WARN {org.apache.synapse.endpoints.EndpointContext} - Suspending endpoint : admin--XXX_APIproductionEndpoint_28 - current suspend duration is : 30000ms - Next retry after : Tue Dec 06 08:37:43 UTC 2016 {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:37:13,693] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 101507, ERROR_MESSAGE = Error in Sender {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1] [] [2016-12-06 08:37:13,694] WARN {org.apache.synapse.transport.passthru.SourceHandler} - Connection time out after request is read: http-incoming-566592 {org.apache.synapse.transport.passthru.SourceHandler} TID: [-1234] [] [2016-12-06 08:37:14,331] INFO {org.apache.synapse.endpoints.EndpointContext} - Endpoint : admin--XXX_APIproductionEndpoint_28 currently SUSPENDED will now be marked active since it processed its last message {org.apache.synapse.endpoints.EndpointContext} TID: [-1] [] [2016-12-06 08:37:14,620] WARN {org.apache.synapse.transport.passthru.TargetHandler} - http-outgoing-16759: Connection time out while in state: REQUEST_DONE {org.apache.synapse.transport.passthru.TargetHandler} TID: [-1234] [] [2016-12-06 08:37:14,621] WARN {org.apache.synapse.endpoints.EndpointContext} - Endpoint : admin--XXX_APIproductionEndpoint_29 will be marked SUSPENDED as it failed {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:37:14,621] WARN {org.apache.synapse.endpoints.EndpointContext} - Suspending endpoint : admin--XXX_APIproductionEndpoint_29 - current suspend duration is : 30000ms - Next retry after : Tue Dec 06 08:37:44 UTC 2016 {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:37:14,621] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 101507, ERROR_MESSAGE = Error in Sender {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:14,818] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:15,255] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:29,543] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:35,137] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:35,568] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:35,990] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:36,409] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:37,899] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:38,327] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:41,129] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:41,545] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:37:42,969] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:38:09,156] INFO {org.apache.synapse.endpoints.EndpointContext} - Endpoint : admin--XXX_APIproductionEndpoint_29 currently SUSPENDED will now be marked active since it processed its last message {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:38:17,817] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1] [] [2016-12-06 08:39:16,163] WARN {org.apache.synapse.transport.passthru.SourceHandler} - Connection time out after request is read: http-incoming-566604 {org.apache.synapse.transport.passthru.SourceHandler} TID: [-1] [] [2016-12-06 08:39:19,169] WARN {org.apache.synapse.transport.passthru.SourceHandler} - Connection time out after request is read: http-incoming-566640 {org.apache.synapse.transport.passthru.SourceHandler} TID: [-1234] [] [2016-12-06 08:39:19,648] ERROR {org.apache.synapse.transport.passthru.PassThroughHttpSender} - Failed to submit the response {org.apache.synapse.transport.passthru.PassThroughHttpSender} java.lang.NullPointerException TID: [-1234] [] [2016-12-06 08:39:19,649] ERROR {org.apache.synapse.core.axis2.Axis2Sender} - Access-Control-Allow-Headers:authorization,Access-Control-Allow-Origin,Content-Type,SOAPAction,Access-Control-Allow-Methods:GET,Access-Control-Allow-Origin:*,Content-Type:application/json,<?xml version='1.0' encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="http://www.w3.org/2003/05/soap-envelope"><soapenv:Body/></soapenv:Envelope> Unexpected error sending message back {org.apache.synapse.core.axis2.Axis2Sender} org.apache.axis2.AxisFault: Failed to submit the response at org.apache.synapse.transport.passthru.PassThroughHttpSender.handleException(PassThroughHttpSender.java:613) at org.apache.synapse.transport.passthru.PassThroughHttpSender.invoke(PassThroughHttpSender.java:266) at org.apache.axis2.engine.AxisEngine.send(AxisEngine.java:442) Caused by: java.lang.NullPointerException TID: [-1234] [] [2016-12-06 08:39:19,650] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 0, ERROR_MESSAGE = Access-Control-Allow-Headers:authorization,Access-Control-Allow-Origin,Content-Type,SOAPAction,Access-Control-Allow-Methods:GET,Access-Control-Allow-Origin:*,Content-Type:application/json,<?xml version='1.0' encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="http://www.w3.org/2003/05/soap-envelope"><soapenv:Body/></soapenv:Envelope> Unexpected error sending message back {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:39:19,688] WARN {org.apache.synapse.core.axis2.Axis2Sender} - Trying to send a response to an already responded client request - Rest API Context : /rest {org.apache.synapse.core.axis2.Axis2Sender} TID: [-1] [] [2016-12-06 08:39:20,249] WARN {org.apache.synapse.transport.passthru.ConnectCallback} - Connection refused or failed for : internal-vpc-connect-api-1883227725.ap-southeast-1.elb.amazonaws.com/x.x.x.43:80 {org.apache.synapse.transport.passthru.ConnectCallback} TID: [-1234] [] [2016-12-06 08:39:20,252] WARN {org.apache.synapse.endpoints.EndpointContext} - Endpoint : admin--XXX_APIproductionEndpoint_29 will be marked SUSPENDED as it failed {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:39:20,254] WARN {org.apache.synapse.endpoints.EndpointContext} - Suspending endpoint : admin--XXX_APIproductionEndpoint_29 - current suspend duration is : 30000ms - Next retry after : Tue Dec 06 08:39:50 UTC 2016 {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:39:20,254] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 101503, ERROR_MESSAGE = Error connecting to the back end {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:39:20,254] ERROR {org.apache.synapse.transport.passthru.PassThroughHttpSender} - Failed to submit the response {org.apache.synapse.transport.passthru.PassThroughHttpSender} java.lang.NullPointerException TID: [-1234] [] [2016-12-06 08:39:20,255] ERROR {org.apache.synapse.core.axis2.Axis2Sender} - Accept-Encoding:gzip, deflate,Access-Control-Allow-Headers:authorization,Access-Control-Allow-Origin,Content-Type,SOAPAction,Access-Control-Allow-Methods:GET,Access-Control-Allow-Origin:*,Content-Type:application/xml,password:Hjfawx99@@,username:[email protected],X-Forwarded-For:76.79.103.18,X-Forwarded-Port:443,X-Forwarded-Proto:https,<?xml version='1.0' encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="http://www.w3.org/2003/05/soap-envelope"><soapenv:Body><am:fault xmlns:am="http://wso2.org/apimanager"><am:code>101503</am:code><am:type>Status report</am:type><am:message>Runtime Error</am:message><am:description>Error connecting to the back end</am:description></am:fault></soapenv:Body></soapenv:Envelope> Unexpected error sending message back {org.apache.synapse.core.axis2.Axis2Sender} org.apache.axis2.AxisFault: Failed to submit the response at org.apache.synapse.transport.passthru.PassThroughHttpSender.handleException(PassThroughHttpSender.java:613) at org.apache.synapse.transport.passthru.PassThroughHttpSender.invoke(PassThroughHttpSender.java:266) at org.apache.axis2.engine.AxisEngine.send(AxisEngine.java:442) Caused by: java.lang.NullPointerException TID: [-1234] [] [2016-12-06 08:39:20,255] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 101503, ERROR_MESSAGE = Error connecting to the back end {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:39:20,256] WARN {org.apache.synapse.core.axis2.Axis2Sender} - Trying to send a response to an already responded client request - Rest API Context : /rest {org.apache.synapse.core.axis2.Axis2Sender} TID: [-1] [] [2016-12-06 08:39:22,936] WARN {org.apache.synapse.transport.passthru.ConnectCallback} - Connection refused or failed for : internal-vpc-connect-api-1883227725.ap-southeast-1.elb.amazonaws.com/x.x.x.43:80 {org.apache.synapse.transport.passthru.ConnectCallback} TID: [-1234] [] [2016-12-06 08:39:22,942] WARN {org.apache.synapse.endpoints.EndpointContext} - Endpoint : admin--XXX_APIproductionEndpoint_29 will be marked SUSPENDED as it failed {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:39:22,945] WARN {org.apache.synapse.endpoints.EndpointContext} - Suspending endpoint : admin--XXX_APIproductionEndpoint_29 - last suspend duration was : 30000ms and current suspend duration is : 30000ms - Next retry after : Tue Dec 06 08:39:52 UTC 2016 {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:39:22,945] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 101503, ERROR_MESSAGE = Error connecting to the back end {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:39:23,363] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} x 34 of similiar logs TID: [-1234] [] [2016-12-06 08:39:52,303] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Executing default 'fault' sequence, ERROR_CODE = 303001, ERROR_MESSAGE = Currently , Address endpoint : [ Name : admin--XXX_APIproductionEndpoint_29 ] [ State : SUSPENDED ] {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:39:53,910] INFO {org.apache.synapse.endpoints.EndpointContext} - Endpoint : admin--XXX_APIproductionEndpoint_29 currently SUSPENDED will now be marked active since it processed its last message {org.apache.synapse.endpoints.EndpointContext} TID: [-1234] [] [2016-12-06 08:42:19,456] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1] [] [2016-12-06 08:42:56,120] INFO {org.wso2.andes.kernel.AndesRecoveryTask} - Running DB sync task. {org.wso2.andes.kernel.AndesRecoveryTask} TID: [-1234] [] [2016-12-06 08:44:18,039] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:46:17,939] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:46:36,177] WARN {org.wso2.carbon.apimgt.keymgt.service.thrift.APIKeyValidationServiceImpl} - Invalid session id for thrift authenticator. {org.wso2.carbon.apimgt.keymgt.service.thrift.APIKeyValidationServiceImpl} TID: [-1234] [] [2016-12-06 08:46:36,177] ERROR {org.wso2.carbon.apimgt.keymgt.service.thrift.APIKeyValidationServiceImpl} - Error in invoking validate key via thrift.. {org.wso2.carbon.apimgt.keymgt.service.thrift.APIKeyValidationServiceImpl} TID: [-1234] [] [2016-12-06 08:46:36,177] WARN {org.wso2.carbon.apimgt.gateway.handlers.security.thrift.ThriftKeyValidatorClient} - Login failed.. Authenticating again.. {org.wso2.carbon.apimgt.gateway.handlers.security.thrift.ThriftKeyValidatorClient} TID: [-1234] [] [2016-12-06 08:46:36,231] INFO {org.wso2.carbon.core.services.util.CarbonAuthenticationUtil} - '[email protected] [-1234]' logged in at [2016-12-06 08:46:36,231+0000] from IP address {org.wso2.carbon.core.services.util.CarbonAuthenticationUtil} TID: [-1234] [] [2016-12-06 08:48:17,776] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:49:18,033] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:50:17,748] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:52:18,419] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:54:18,051] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1234] [] [2016-12-06 08:56:17,815] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator} TID: [-1] [] [2016-12-06 08:57:56,120] INFO {org.wso2.andes.kernel.AndesRecoveryTask} - Running DB sync task. {org.wso2.andes.kernel.AndesRecoveryTask} TID: [-1234] [] [2016-12-06 08:58:18,054] INFO {org.apache.synapse.mediators.builtin.LogMediator} - STATUS = Message dispatched to the main sequence. Invalid URL., RESOURCE = / {org.apache.synapse.mediators.builtin.LogMediator}
Upvotes: 0
Views: 3991
Answers (1)
Scott
Reputation: 46
From your logs you can see that your backend was suspended and that is the cause of your 500 error. APIM will unsuspend the endpoint after a set time out period and allow you to try the endpoint again. It seems the backend was having some issues where it was most of the time working but sometimes unavailable causing the suspension of the endpoint.
Since this report is so old I'm using the most current documentation. You can see the same error code of 303001 on the Endpoint Suspension page.
I further created a quick demo of this situation using APIM 4.1.0 on my laptop and used an endpoint url of bogus.endpoint which of course will not resolve. I received the following message back using postman:
{
"code": "303001",
"type": "Status report",
"message": "Runtime Error",
"description": "Currently , Address endpoint : [ Name : DemoSuspention--vv1_APIproductionEndpoint ] [ State : SUSPENDED ]"
}
And it gave me a status result of: 500 Internal Server Error 40 ms 732 B
Normally when I run into this type of situation I reach out to the technical point of contact for the backend and report what I'm seeing. They normally can locate some kind of issue in their logs and then address it by either restarting a server or fixing a bug depending on what is found.
Upvotes: 0
Related Questions
- WSO2 API Manager Received fatal alert: handshake_failure
- WSO2 API Manager ERROR_CODE = 101503, ERROR_MESSAGE = Error in Sender
- Why APIs of WSO2 APIManager can not be called successfully?
- WSO2 APi Manager Response Code 0
- WSO2 API Manager "error": "no response from server"
- Error 500 : The page cannot be displayed. The server encountered an internal error or misconfiguration and was unable to complete your request
- WSO2 APIM API invocation error
- WSO2 API Manager : API Creation Issue
- WSO2 API Manager periodic error on console
- Wso2 API Manager ERROR_CODE = 101508, Error in Sender