python POST request taking entire timeout length to send request due to environment issue on App Engine standard

[Shaan]

I have an issue on google cloud app engine standard environment where a python request is taking it's entire timeout period to send a request

    import requests

    # Set token, headers, data variables here (vary each time)

    r = requests.post(f'https://api.popularwebsite.com/endpoint?access_token={token}', headers=headers, data=data)

    timetaken = r.elapsed.total_seconds()

At the end of this code, timetaken is some value between 127 and 128 seconds (127 is the default timeout for request). The request is successful and returns a 200. This request should be near instantaneous ( < 1 sec)

I can add some logging and in the logs, I can see the request isn't sent until after 127 seconds

Logging code:

import logging

import http.client

http.client.HTTPConnection.debuglevel = 1

logging.basicConfig()

logging.getLogger().setLevel(logging.DEBUG)

requests_log = logging.getLogger("requests.packages.urllib3")

requests_log.setLevel(logging.DEBUG)

requests_log.propagate = True

Logs:

    2021-03-15 (04:02:01.522) DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): api.popularwebsite.com.com:443

    2021-03-15 (04:04:08.646) send: b'{"myJsonPayload": 1234}'

Some further observations:

* I can pass a timeout argument of n seconds to the post function, and the request will take that amount of time to complete. If I pass a timeout of 0.5 seconds, the request will complete in 0.5 seconds. This indicates it doesn't need the full 127 seconds to complete

* There is no issue with the server I am trying to reach. I can send a request to the endpoint without issue from my local machine or other cloud hosts

* My program does not seem to have any issue sending request to other endpoints. It seems like the preconditions for the issue are a combination of my google cloud app engine server, and this particular url

* The problem comes and goes. Requests will behave normally for several hours, and then need the entire timeout for several hours. I cannot notice any patterns in what conditions cause the issue to come and go. It seems random

* This code has been running without issue on app engine for 2 years, and only started having this issue about a week ago. I also deployed an old version of the code and saw the problem still occurs. This indicates the issue is not due to a bug in my code, but some environment issue with app engine.

* When the issue is occurring, redeploying using "gcloud app deploy --no-cache" will occasionally fix the problem, but not always

*  There are no errors or warnings in the stackdriver logs

* Looking through the logs, I noticed sometimes when the issue goes away, there is a ghost request to some endpoint on my application, my applications seems to receive a request that was never sent. For example, I might see

2021-03-22 06:00:08 default[20210321t221218] "GET /someendpoint HTTP/1.1" 200
2021-03-22 06:00:14 default[20210321t221218] "GET /someendpoint HTTP/1.1" 200

When only 1 request was sent. The issue going away doesn't always correspond to a ghost request, but every ghost request has only been observed when the issue is occurring and my app starts behaving normally every time after a ghost request

* I am using python 3.7.5. I have tried using multiple versions of the python request library. 

* Here is the output to $ gcloud version

Google Cloud SDK 332.0.0
alpha 2021.03.12
beta 2021.03.12
bq 2.0.65
core 2021.03.12
gsutil 4.59

* Here is my app.yaml file

runtime: python37

entrypoint: gunicorn -b :$PORT --chdir src main:app --timeout 300

instance_class: F1

(I added the --timeout 300 to accommodate the long requests. Before that, my server was timing out before the long requests would complete)

Any advice on how to solve the issue or further troubleshoot would be appreciated

[vladoi]

Hello, 

Thank you for reporting this issue. 

Reading the use case description is hard to identify the root cause of your issue. 

In order to better isolate the issue, can you please tell me if you could reproduce the issue by calling another endpoint that [1].

If you get the same issue by calling another endpoint, then it might be related to App Engine service. 

Otherwise, I think it might be related to the server you are calling.

 ----------------------------

[1]. https://api.popularwebsite.com/endpoint?access_token={token}'