Endpoints latency overhead

[patric...@leansys.fr]

Hi all,

I'm having a weird issue with Google Endpoints latency overhead.

I have a service deployed on GAE with Endpoint in front of it. I see I have huge response times from time to time and, while my api has a stable response time (around 10ms), the whole request from the caller point of view may take about 15s to complete.

I checked the Endpoints dashboard and opened the Endpoints latency overhead and saw unexpected latency spikes with, for example, a 50th percentile @11ms, but a 95th percentile @8.5s and a 98th percentile @13.5s while my api (backend latency) was at a nice 98th percentile @11ms.

Is there something I did not understand or an issue with Endpoints ?

Cheers,

Patrice

[D. T.]

We need more details. What is your platform? If App Engine Standard, Python or Java? Do you have any traces or logs for these long requests?

Daniel Tang |

Software Engineer |

ta...@google.com |

Google LLC

--
You received this message because you are subscribed to the Google Groups "Google Cloud Endpoints" group.
To unsubscribe from this group and stop receiving emails from it, send an email to google-cloud-endp...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/google-cloud-endpoints/5fa729a8-bc77-484b-bcb6-39b73b32855d%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Dan Ciruli]

Also, can you tell us what region your backend is running in?

Thanks -

DC

To view this discussion on the web visit https://groups.google.com/d/msgid/google-cloud-endpoints/CABuQ5K-APhmU8ywVjwUmeOJUUu5Oo-F_x8diYpf0Mn-CWRaZHQ%40mail.gmail.com.

For more options, visit https://groups.google.com/d/optout.

--

DC

[patric...@prestataires.boulanger.com]

Hello,

Here are the missing pieces of information : I am running a go1.10 runtime on a Flexible environment in europe-west. The scaling is set to use the default value.

Here is also an extract from stackdriver logging of the issue I am facing fro mtimes to times. The overall latency is 15.609s, but my app altency is 0.003ms :

 

 

 

 

 

 

 

 

}

 

 

 

}

 

 

}

Patrice

[Andrew Gunsch]

+Wayne Zhang since this is on Flex, any tips on investigating high-latency processing from ESP?

--

You received this message because you are subscribed to the Google Groups "Google Cloud Endpoints" group.
To unsubscribe from this group and stop receiving emails from it, send an email to google-cloud-endp...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/google-cloud-endpoints/847809a8-28b0-484c-bd61-c36308643cb2%40googlegroups.com.

[Wayne Zhang]

We need to use cloud trace to investigate ESP latency.   It seems that there is a trace id for the app, but not sure ESP has the trace or not.

Trace can be turn on by client, or by ESP (1 of 1000, auto sampling), or by the app.   If by the app,  ESP will not have trace.   Ask users to turn on cloud trace from the client to see if they can catch a big latency one.

[Andrew Gunsch]

+Wesley

Is there a way to turn tracing on ESP in Flex? Isn't that enabled by default?

[Wesley Wong]

Tracing is enabled by default, unless it was specifically disabled.

[Wayne Zhang]

ESP default doesn't turn on trace for every request, only 1 in every 1000 requests.   We have to hope that the request with trace is the one with long latency.  If the long latency happens on every request,  this will work.

If it is on some requests, long tail percentile requests, it will not help. 

[patric...@leansys.fr]

High latency responses have indeed been captured and available in stackdriver trace. Here is one example where Backend latency in trace is 767ms while in stackdriver log appLatency is 2ms with a http request latency at 774ms.

<MY REDACTED SERVICE>.appspot.com/1.<MY_REDACTED_SERVICE>.SearchQuery (774.889 ms)

The linked log entry is :

{
 
httpRequest: {
  latency: "0.774s"  

  referer: "-"  
  remoteIp: "<REDACTED>"  
  requestMethod: "POST"  
  requestUrl: "<REDACTED>"  

  responseSize: "1084"  
  status: 200  
  userAgent: "<REDACTED>"  
 }
 insertId: "rqvm6sg4gjcvb6" 
 
jsonPayload: {
  appLatencySeconds: "0.002"  
 
httpRequest: {
   protocol: "HTTP/1.1"   
  }
  latencySeconds: "0.774"  
  trace: "0080287b82185d5ad5d996758e048863"  
 }
 
labels: {
  appengine.googleapis.com/instance_name: "<REDACTED>-20181106t205551-3vbj"  
  appengine.googleapis.com/trace_id: "0080287b82185d5ad5d996758e048863"  
  compute.googleapis.com/resource_id: "<REDACTED>"  
  compute.googleapis.com/resource_name: "<REDACTED>"  
  compute.googleapis.com/zone: "europe-west1-b"  
 }
 logName: "projects/<REDACTED>/logs/appengine.googleapis.com%2Fnginx.request" 
 receiveTimestamp: "2018-11-27T09:39:13.639931889Z" 
 
resource: {
 
labels: {
   module_id: "<REDACTED>"   
   project_id: "<REDACTED>"   
   version_id: "20181106t205551"   
  }
  type: "gae_app"  
 }
 timestamp: "2018-11-27T09:39:08.763Z" 
}

Is this what you wanted me to get from ESP tracing ?

Patrice