Странное поведение блокировки с gevent/grequests по HTTPS

Question

Следующий код отправляет запрос каждые 200 мс и должен обрабатывать ответы асинхронно всякий раз, когда они приходят.

По HTTP работает как и ожидалось - запрос отправляется каждые 200 мс, а ответный вызов ответа вызывается независимо всякий раз, когда приходит ответ. Тем не менее, по протоколу HTTPS запросы значительно задерживаются всякий раз, когда приходит ответ (хотя мой обработчик ответа не работает). Обратный вызов ответа, кажется, вызывается дважды для каждого запроса, один раз с ответом нулевой длины (редактирование: это из-за перенаправления и, похоже, не связано с проблемой блокировки, спасибо Padraic).

Что может быть причиной этого блокирующего поведения по протоколу HTTPS? (www.bbc.co.uk - это всего лишь пример, который географически далеко от меня, но это происходит со всеми проверенными мной серверами).

grequests_test.py

import time 
import sys 
import grequests 
import gevent 

def cb(res, **kwargs): 
    print("**** Response", time.time(), len(res.text)) 

for i in range(10): 
    unsent = grequests.get(sys.argv[1], hooks={'response': cb}) 
    print("Request", time.time()) 
    grequests.send(unsent, grequests.Pool(1)) 
    gevent.sleep(0.2) 
gevent.sleep(5) 

$ ipython2 grequests_test.py 'http://www.bbc.co.uk' (ожидаемый результат)

('Request', 1459050191.499266) 
('Request', 1459050191.701466) 
('Request', 1459050191.903223) 
('Request', 1459050192.10403) 
('Request', 1459050192.305626) 
('**** Response', 1459050192.099185, 179643) 
('Request', 1459050192.506476) 
('**** Response', 1459050192.307869, 179643) 
('Request', 1459050192.707745) 
('**** Response', 1459050192.484711, 179643) 
('Request', 1459050192.909376) 
('**** Response', 1459050192.696583, 179643) 
('Request', 1459050193.110528) 
('**** Response', 1459050192.870476, 179643) 
('Request', 1459050193.311601) 
('**** Response', 1459050193.071679, 179639) 
('**** Response', 1459050193.313615, 179680) 
('**** Response', 1459050193.4959, 179643) 
('**** Response', 1459050193.687054, 179680) 
('**** Response', 1459050193.902827, 179639) 

ipython2 grequests_test.py 'https://www.bbc.co.uk' (запросы посылаются в конце)

('Request', 1459050203.24336) 
('Request', 1459050203.44473) 
('**** Response', 1459050204.423302, 0) 
('Request', 1459050204.424748) <------------- THIS REQUEST TIME IS LATE 
('**** Response', 1459050205.294426, 0) 
('Request', 1459050205.296722) 
('Request', 1459050205.497924) 
('**** Response', 1459050206.456572, 0) 
('Request', 1459050206.457875) 
('**** Response', 1459050207.363188, 0) 
('**** Response', 1459050208.247189, 0) 
('Request', 1459050208.249579) 
('**** Response', 1459050208.250645, 179643) 
('**** Response', 1459050208.253638, 179643) 
('Request', 1459050208.451083) 
('**** Response', 1459050209.426556, 0) 
('Request', 1459050209.428032) 
('**** Response', 1459050209.428929, 179643) 
('**** Response', 1459050210.331425, 0) 
('**** Response', 1459050211.247793, 0) 
('Request', 1459050211.251574) 
('**** Response', 1459050211.252321, 179643) 
('**** Response', 1459050211.25519, 179680) 
('**** Response', 1459050212.397186, 0) 
('**** Response', 1459050213.299109, 0) 
('**** Response', 1459050213.588854, 179588) 
('**** Response', 1459050213.590434, 179643) 
('**** Response', 1459050213.593731, 179643) 
('**** Response', 1459050213.90507, 179643) 
('**** Response', 1459050213.909386, 179643) 

Обратите внимание, что первый ответ, по-видимому, прибывает долго после следующего запроса должно быть отправлено, но не было отправлено. Почему спал не вернулся, и следующий запрос отправлен, прежде чем этот первый ответ придет?

Answer 1

текущей итерации grequests содержит следующее:

from gevent import monkey as curious_george 
curious_george.patch_all(thread=False, select=False) 

Нарушитель часть select=False - удаление этого или вручную вызова monkey.patch_select() решает эту проблему. Я не уверен, что это имеет другие побочные эффекты.

Answer 2

Дополнительные ответы и ответы 0 длина легко объяснить, если вы добавите print(res.status_code) вы увидите много 301-х годов, как и в случае https://www.bbc.co.uk вы получите перенаправлены http://www.bbc.co.uk так вот почему вы видите отдельно оплачиваемые предметы ответы и 0 возвращаемые для len(res.text), вы можете увидеть ниже вывод:

In [11]: def cb(res, **kwargs): 
    ....:   print(res.status_code) 
    ....:   print("**** Response", time.time(), len(res.text)) 
    ....:  

In [12]: for i in range(10): 
    ....:   unsent = grequests.get("https://www.bbc.co.uk", hooks={'response': cb}) 
    ....:   print("Request", time.time()) 
    ....:   grequests.send(unsent, grequests.Pool(1)) 
    ....:   gevent.sleep(0.2) 
    ....: gevent.sleep(5) 
    ....: 
('Request', 1459368704.32843) 
301 
('**** Response', 1459368704.616453, 0) 
('Request', 1459368704.618786) 
301 
('**** Response', 1459368704.937159, 0) 
('Request', 1459368704.941069) 
200 
('**** Response', 1459368704.943034, 141486) 
301 
('**** Response', 1459368705.496423, 0) 
('Request', 1459368705.498991) 
200 
('**** Response', 1459368705.50162, 141448) 
301 
('**** Response', 1459368705.784145, 0) 
('Request', 1459368705.785769) 
200 
('**** Response', 1459368705.786772, 141486) 
301 
('**** Response', 1459368706.110865, 0) 
('Request', 1459368706.114921) 
200 
('**** Response', 1459368706.116124, 141448) 
301 
('**** Response', 1459368706.396807, 0) 
('Request', 1459368706.400795) 
200 
301 
('**** Response', 1459368706.756861, 0) 
('Request', 1459368706.76069) 
200 
('**** Response', 1459368706.763268, 141448) 
('**** Response', 1459368706.488708, 141448) 
301 
('**** Response', 1459368707.065011, 0) 
('Request', 1459368707.069128) 
200 
('**** Response', 1459368707.071981, 141448) 
301 
('**** Response', 1459368707.366737, 0) 
('Request', 1459368707.370713) 
200 
('**** Response', 1459368707.373597, 141448) 
301 
('**** Response', 1459368707.73689, 0) 
200 
('**** Response', 1459368707.743815, 141448) 
200 
('**** Response', 1459368707.902499, 141448) 

Если запустить тот же код, используя сайт, который обслуживает более HTTPS, https://www.google.ie/ в этом примере:

In [14]: for i in range(10): 
    ....:   unsent = grequests.get("https://www.google.ie/", hooks={'response': cb}) 
    ....:   print("Request", time.time()) 
    ....:   grequests.send(unsent, grequests.Pool(1)) 
    ....:   gevent.sleep(0.2) 
    ....: gevent.sleep(5) 
    ....: 
('Request', 1459368895.525717) 
200 
('**** Response', 1459368895.838453, 19682) 
('Request', 1459368895.884151) 
200 
('**** Response', 1459368896.168789, 19650) 
('Request', 1459368896.22553) 
200 
('**** Response', 1459368896.491304, 19632) 
('Request', 1459368896.542206) 
200 
('**** Response', 1459368896.808875, 19650) 
('Request', 1459368896.850575) 
200 
('**** Response', 1459368897.144725, 19705) 
('Request', 1459368897.173744) 
200 
('**** Response', 1459368897.45713, 19649) 
('Request', 1459368897.491821) 
200 
('**** Response', 1459368897.761675, 19657) 
('Request', 1459368897.792373) 
200 
('**** Response', 1459368898.331791, 19683) 
('Request', 1459368898.350483) 
200 
('**** Response', 1459368898.836108, 19713) 
('Request', 1459368898.855729) 
200 
('**** Response', 1459368899.148171, 19666) 

Вы увидите, что поведение отличается. Мы получаем 10 ответов и нет ответов 0. Вы должны проверить status_code в своей функции, чтобы убедиться, что вы получаете то, что хотите. В приведенном выше примере объясняется то, что вы видите на сайте bbc, и, скорее всего, то, что происходит для других.