Вызов локального хост-сервера в python влечет за собой большие накладные расходы - PullRequest
Новая
       17

Вызов локального хост-сервера в python влечет за собой большие накладные расходы

0 голосов
/ 02 ноября 2018

Мой код Python делает звонки на сервер REST на localhost. Сам сервер регистрирует метрики (то есть время обработки) и отправляет свои собственные измерения в ответе для целей отладки.

По какой-то причине, без моего ведома, возникают большие издержки при вызове сервера localhost из кода Python. Я измерил время, используя простой код для проверки: 

import logging
import requests
import time
import os
os.environ['no_proxy'] = '127.0.0.1,localhost'
# asserting that the connection is being re-used - this prints it out
logging.basicConfig(level=logging.DEBUG)
# re-use the session
s = requests.Session()
# try variations of host to see if there is a difference
localhost = "localhost"
local_ip = "127.0.0.1"

# https://github.com/requests/requests/issues/879
NO_PROXY = {
    'no': 'pass',
}

def measure():
    url = "http://{}:8888/endpoint".format(localhost)
    start = time.time()
    response = s.get(url, proxies=NO_PROXY)
    end = time.time()
    print("took {} ms".format((end-start)*1000))

    url = "http://{}:8888/endpoint".format(local_ip)
    start = time.time()
    response = s.get(url, proxies=NO_PROXY)
    end = time.time()
    print("took {} ms".format((end-start)*1000))

for i in range(0,1000):
    make_request()
    ping()

Логи выглядят примерно так же, как 

DEBUG:urllib3.connectionpool:Starting new HTTP connection (1): localhost:8888
DEBUG:urllib3.connectionpool:http://localhost:8888 "GET /endpoint HTTP/1.1" 200 4
took 7.76600837708 ms
DEBUG:urllib3.connectionpool:Starting new HTTP connection (1): 127.0.0.1:8888
DEBUG:urllib3.connectionpool:http://127.0.0.1:8888 "GET /endpoint HTTP/1.1" 200 4
took 4.73213195801 ms
DEBUG:urllib3.connectionpool:http://localhost:8888 "GET /endpoint HTTP/1.1" 200 4
took 1.47581100464 ms
DEBUG:urllib3.connectionpool:http://127.0.0.1:8888 "GET /endpoint HTTP/1.1" 200 4
took 1.25908851624 ms
DEBUG:urllib3.connectionpool:http://localhost:8888 "GET /endpoint HTTP/1.1" 200 4
took 1.25503540039 ms
DEBUG:urllib3.connectionpool:http://127.0.0.1:8888 "GET /endpoint HTTP/1.1" 200 4
took 1.21402740479 ms
DEBUG:urllib3.connectionpool:http://localhost:8888 "GET /endpoint HTTP/1.1" 200 4
took 1.31893157959 ms
DEBUG:urllib3.connectionpool:http://127.0.0.1:8888 "GET /endpoint HTTP/1.1" 200 4
took 1.54900550842 ms

Я также напечатал заголовки, чтобы получить представление о том, сколько данных передается в этом запросе (всего около 300 байт): 

{'Content-Length': '138', 'Accept-Encoding': 'gzip, deflate', 'Accept': '*/*', 'User-Agent': 'python-requests/2.19.1','Connection': 'keep-alive', 'debug': 'true', 'Content-Type': 'application/json'}

Я вижу, что начальный вызов медленный, но более поздние вызовы повторно используют соединение (значительно быстрее), но, тем не менее, когда я сопоставляю журналы сервера, я вижу, что эти 1,5 мс - относительно длительное время. Сервер работает значительно быстрее и занимает менее 0,1 мс, что наводит меня на мысль, что при вызове локального хоста выплачивается серьезный штраф.

Кроме того, мы видим, что "content-length" маленький - в данном конкретном случае это было 138 

Just for comparison with regular "ping" command:

ping localhost
PING localhost (127.0.0.1): 56 data bytes
64 bytes from 127.0.0.1: icmp_seq=0 ttl=64 time=0.051 ms
64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.096 ms
64 bytes from 127.0.0.1: icmp_seq=2 ttl=64 time=0.073 ms
64 bytes from 127.0.0.1: icmp_seq=3 ttl=64 time=0.089 ms
64 bytes from 127.0.0.1: icmp_seq=4 ttl=64 time=0.120 ms
64 bytes from 127.0.0.1: icmp_seq=5 ttl=64 time=0.078 ms
64 bytes from 127.0.0.1: icmp_seq=6 ttl=64 time=0.097 ms

так ~ в 20 раз быстрее. Я понимаю, что он использует совершенно другой протокол, но все еще только для справки.

...