Error occurs after 30-40 consecutive urlfetch

[kyeongwook Ma]

Hi GAE support,

I am a developer using the GAE with Golang and gin.

I included urlfetch in the service to use a third party service (for example, AWS SNS push service).

The urlfetch is successful for the first few times, but when we send 30-40 consecutive urlfetch, it keeps on giving an error.

The specific error message is:

WARNING  2016-08-09 13:29:56,592 urlfetch_stub.py:540] Stripped prohibited headers from URLFetch request: ['Content-Length']

ERROR: context expired before API call urlfetch/Fetch completed

RequestError: send request failed

caused by: Post https://sns.us-west-1.amazonaws.com/: Call error 3: invalid security ticket (context expired)

We also tested urlfetch with other third party services, and we still get the same error messages as above.

 

Is there anybody that can help us with this situation?

Thank you very much for your help.

Best,

Rio

[Evan Jones]

Are you using the Standard Environment? I think this happens if you are trying to do work for longer than the App Engine request timeout (60 seconds), or after you have responded to the original web request. The key words in this error are "context expired", which means this is some sort of timeout. Is it possible that this happens approximately 60 seconds after the initial web request?

I'm not 100% sure, but only if you have a manual scaling backend can you have "long running" requests, and you must use runtime.RunInBackground.

https://cloud.google.com/appengine/docs/go/runtime

https://cloud.google.com/appengine/docs/go/how-requests-are-handled#Go_The_request_timer

[Nicholas (Google Cloud Support)]

Thanks for sharing your issue here.

Based on the expired context error you are receiving, I suspect Evan is most likely correct here.  Nevertheless, more information would definitely help with narrowing down the range of possible issues here:

• You mention sending 30 to 40 consecutive urlfetch requests.  Are these requests all invoked within the handling of a single request?
  
• Are these urlfetch requests to different domains or all the same domain?
  
• If you enable Stackdriver Trace, you'll be able to see how long urlfetch requests are taking during the request lifespan.  Could you provide a screenshot showing how long these take?  It is quite possible that your application is hitting one of the time limits Evan referred to in the documentation.
  

With the information above, I should be in a better position to confirm if this is in fact a timeout issue or know how to investigate further.

On Tuesday, August 9, 2016 at 10:29:30 AM UTC-4, kyeongwook Ma wrote:

[Nicholas (Google Cloud Support)]

Apologies for the follow-up, here's an example of a trace detail showing exact latencies for various RPC calls.  This can be very useful.

On Tuesday, August 9, 2016 at 10:29:30 AM UTC-4, kyeongwook Ma wrote:

[Nicholas (Google Cloud Support)]

Hi there,

Have you had a chance to review some of the recommendations posted here by Evan and myself?  Was any of the advice helpful in troubleshooting?  If this still affects you, could you provide some of the information requested in my previous post?

Looking forward to hearing from you!

On Tuesday, August 9, 2016 at 10:29:30 AM UTC-4, kyeongwook Ma wrote:

[Dustin Oprea]

I have this error constantly, though I'm not explicitly using urlfetch. I'm just using datastore and memcache. As I'm in the early stages of this project, I only recently noticed it happening more frequently after I implemented session management on top of datastore and memcache, but, now, as I actually explicitly push data into memcache, it is now happening constantly. Most often, I'll get this error every time until I flush, it will work once, and then I'll get this error every time afterward.

The requests that are inciting the issue are very simple (try *get* from memcache, do *get* from datastore, *put* to memcache), so they're very quick. The request either completes or fails within a second. Any ideas?

<-- Current user reconcile here.

2016/09/01 03:00:42 DEBUG: Session save not necessary: [DCRBDGRY6RMWANCSJXVLD7GULDH4NZEB6SBAQ3KSFIGA2LP45IIQ]

2016/09/01 03:00:42 DEBUG: Got session: [DCRBDGRY6RMWANCSJXVLD7GULDH4NZEB6SBAQ3KSFIGA2LP45IIQ]

2016/09/01 03:00:42 DEBUG: Found user in session.

<-- Request-specific handler logic here.

2016/09/01 03:00:42 DEBUG: Cache hit: [type.family:522450f6795592f844a27213a2dddf8de169f204]

2016/09/01 03:00:42 ERROR: context expired before API call datastore_v3/Put completed

request URL: /api/1/type/family/522450f6795592f844a27213a2dddf8de169f204

panic: Call error 3: invalid security ticket (context expired)

Maybe if I could understand the nature of the failure and how it might potentially be tricked to fire so early I might be more helpful in providing more information?

Thanks.

Dustin

[Nicholas (Google Cloud Support)]

Dustin,

It's not entirely clear what is happening but it seems like a go context.Context is expiring before the request terminates, causing a panic to bubble up which is not being handled.

Could you provide a trimmed down version of your handler source code so that I can investigate this myself?

On Tuesday, August 9, 2016 at 10:29:30 AM UTC-4, kyeongwook Ma wrote:

[Nicholas (Google Cloud Support)]

Also, just to be certain, are you using the standard or flexible environment?

On Tuesday, August 9, 2016 at 10:29:30 AM UTC-4, kyeongwook Ma wrote:

[Chris Olsen]

I get this error quite often as well. I am using standard environment, and as was mentioned, the request itself is not a long one, but under a second.

[Nick (Cloud Platform Support)]

Hey Chris,

From reading the thread history, it seems that there are potentially two issues brought up by kyeongwook Ma and Dustin Oprea. Although both see an expired context, one is about UrlFetch calls and the other is about Datastore API calls. The mechanism underlying potentially both of them, if they are the same issue, was discussed as being the duration of the request handler.

In your case, we haven't got from your post any details other than that you see this error (exactly as posted by OP? or a similar error?) quite often (how often?) and that your request handler runs under a second. This last fact certainly rules out a request deadline root cause, but leaves a lot undefined.

Given that this thread seems to have exhausted itself and in the first place was not suited to this forum (which is meant for general discussion, not technical support or issue tracking, for which we have Stack Overflow and the Public Issue Tracker, respectively), I'd suggest posting to the Public Issue Tracker with as many technical details about what's occurring as possible. This is the surest way for us to be able to begin looking into the root cause.

Finally, rest assured that we monitor our Stack Overflow tags and the Public Issue Tracker thoroughly - this isn't a redirect into the void but rather simply a question of directing you to the forum among those we monitor where we ourselves can best provide assistance.

Cheers

Nick
Cloud Platform Community Support