python requests-futures slow - not threading properly?

Question

Hi so I have written a multithreaded request and response handler using requests-futures library.

However, it seems to be very slow, and not asynchronous as I would imagine. The output is slow and in order, not interlaced as i would expect if it was threading properly.

My question is why is my code slow, and what can i do to speed it up? An example would be great.

here is the code:

#!/usr/bin/python
import requests
import time
from concurrent.futures import ThreadPoolExecutor
from requests_futures.sessions import FuturesSession

session = FuturesSession(executor=ThreadPoolExecutor(max_workers=12))

def responseCallback( sess, resp ):
    response = resp.text
    if not "things are invalid" in response in response:
        resp.data = "SUCCESS %s" % resp.headers['content-length']
    else:
        resp.data = "FAIL %s" % resp.headers['content-length']

proxies = {
"http":"http://localhost:8080",
"https":"https://localhost:8080"
}

url = 'https://www.examplehere.com/blah/etc/'
headers= {
'Host':'www.examplehere.com',
'Connection':'close',
'Cache-Control':'max-age=0',
'Accept':'text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8',
'Origin':'https://www.examplehere.com',
'User-Agent':'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/533.32 (KHTML, like Gecko) Ubuntu Chromium/34.0.1847.123 Chrome/34.0.1847.123 Safari/337.12',
'Content-Type':'application/x-www-form-urlencoded',
'Referer':'https://www.exampleblah.etc/',
'Accept-Encoding':'gzip,deflate,sdch',
'Accept-Language':'en-US,en;q=0.8,de;q=0.6',
'Cookie':'blah=123; etc=456;',
}

for n in range( 0, 9999 ):
    #wibble = n.zfill( 4 )
    wibble = "%04d" % n
    payload = { 
    'name':'test',
    'genNum':wibble,
    'Button1':'Push+Now'
    }
    #print payload
    #r = requests.post( url, data=payload, headers=headers, proxies=proxies, verify=False )
    future = session.post( url, data=payload, headers=headers, verify=False, background_callback=responseCallback )
    response = future.result()
    print( "%s : %s" % ( wibble, response.data ) )

Ideally i'd like to fix my actual code still using the library I have already utilised, but if it's bad for some reason i'm open to suggestions...

edit: i am currently using python2 with the concurrent.futures backport.

edit: slow - approx one request a second, and not concurrent, but one after the other, so request1, response1, request2, response2 - i would expect them to be interlaced as the requests go out and come in on multiple threads?

Answer 1

The following code is another way to submit multiple requests, work on several of them at a time, then print out the results. The results are printed as they are ready, not necessarily in the same order as when they were submitted.

It also uses extensive logging, to help debug issues. It captures the payload for logging. Multithreaded code is hard, so more logs is more better!

source

import logging, sys

import concurrent.futures as cf
from requests_futures.sessions import FuturesSession

URL = 'http://localhost'
NUM = 3

logging.basicConfig(
    stream=sys.stderr, level=logging.INFO,
    format='%(relativeCreated)s %(message)s',
    )

session = FuturesSession()
futures = {}

logging.info('start')
for n in range(NUM):
    wibble = "%04d" % n
    payload = { 
        'name':'test',
        'genNum':wibble,
        'Button1':'Push+Now'
    }
    future = session.get( URL, data=payload )
    futures[future] = payload

logging.info('requests done, waiting for responses')

for future in cf.as_completed(futures, timeout=5):
    res = future.result()
    logging.info(
        "wibble=%s, %s, %s bytes",
        futures[future]['genNum'],
        res,
        len(res.text),
    )

logging.info('done!')

output

69.3101882935 start
77.9430866241 Starting new HTTP connection (1): localhost
78.3731937408 requests done, waiting for responses
79.4050693512 Starting new HTTP connection (2): localhost
84.498167038 wibble=0000, <Response [200]>, 612 bytes
85.0481987 wibble=0001, <Response [200]>, 612 bytes
85.1981639862 wibble=0002, <Response [200]>, 612 bytes
85.2642059326 done!