Strano comportamento di blocco con gevent/grequests su HTTPS

Question

Il seguente codice invia una richiesta ogni 200 ms e dovrebbe gestire le risposte in modo asincrono ogni volta che vengono.

Su HTTP funziona come previsto - una richiesta viene inviata ogni 200 ms e la richiamata della risposta viene chiamata indipendentemente ogni volta che arriva una risposta. Su HTTPS, tuttavia, le richieste vengono significativamente ritardate ogni volta che arriva una risposta (anche se il mio gestore di risposta non funziona). Il callback della risposta sembra essere chiamato due volte per ogni richiesta, una volta con una risposta di lunghezza zero (edit: questo è a causa di un reindirizzamento e sembra non correlato al problema del blocco, grazie Padraic).

Che cosa potrebbe causare questo comportamento di blocco su HTTPS? (www.bbc.co.uk è solo un esempio geograficamente lontano da me, ma succede con tutti i server che ho testato).

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' (risultato atteso)

('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' (richieste vengono inviate in ritardo)

('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) 

Si noti che la prima risposta sembra arrivare molto dopo la richiesta successiva se è stata inviata ma non è stata inviata. Perché il sonno non è tornato e la richiesta successiva è stata inviata prima che arrivasse la prima risposta?

Answer 1

L'attuale iterazione grequests contiene:

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

La parte incriminato è select=False - rimozione di questa o chiamando manualmente monkey.patch_select() risolve il problema. Non sono sicuro se questo ha altri effetti collaterali.

Answer 2

Le risposte extra e le 0 Risposte lunghezza sono facilmente spiegabili, se si aggiunge un print(res.status_code) vedrete un sacco di 301 di come nel caso di https://www.bbc.co.uk si ottiene reindirizzato a http://www.bbc.co.uk così è per questo che si vede extra risposte e 0 restituite per il len(res.text), è possibile visualizzare l'output di seguito:

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) 

Se corriamo lo stesso codice utilizzando un sito che serve oltre https, https://www.google.ie/ in questo esempio:

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) 

Vedrai che il comportamento è diverso. Riceviamo 10 risposte e nessuna risposta di lunghezza 0. Dovresti controllare lo status_code nella tua funzione per verificare se ottieni quello che vuoi. L'esempio sopra spiega cosa si vede per il sito di BBC e molto probabilmente cosa sta succedendo per gli altri.