Bert-as-service: Disastrous performance downgrade after 30mins of continuous requests

Created on 4 Jul 2019 · 1Comment · Source: hanxiao/bert-as-service

Prerequisites

Please fill in by replacing [ ] with [x].

[ ] Are you running the latest bert-as-service?
[x] Did you follow the installation and the usage instructions in README.md?
[x] Did you check the FAQ list in README.md?
[x] Did you perform a cursory search on existing issues?

System information

Some of this information can be collected via this script.

OS Platform and Distribution (e.g., Linux Ubuntu 16.04): Centos 7
TensorFlow installed from (source or binary): binary
TensorFlow version:1.12
Python version: 3.6
bert-as-service version: server 1.83 client 1.91
GPU model and memory: Tesla P100 16G
CPU model and memory:16 Cores, 118G

Description

I've 100% followed homepage tutorial to get sentence embedding. Everything works fine until BertServer had processed billions of requests from BertClient .Then, Server side suffered severe speed degradation from taking just 200ms to encode a batch of 200 sentences to 10s. I personally make sure a new BertClient is created for each request under multiprocessing circumstance.

Then I try to locate which part of code has taken so much time. It turn out the following snippet in _run method of BertServer can take a few hundred microseconds or even 10 seconds to execute, depending on the number of requests server has satisfied. This dictionary actually contains statistics about server status, like number of requests received from startup. Every time a BertClient is created and send a request, the following code is executed and BertClient get status info about server side.

Actually, I created a pool of 30 processes and continuously send the same request of batch 200 to server side for, like, 30mins or even more. I've also add a few logger.info between each possible line of code causing my issue. Of course, logger is configured to log time, microsecond precision. In my code, there are two logger.info before and after the following

                status_runtime = {'client': client.decode('ascii'),
                                  'num_process': len(self.processes),
                                  'ventilator -> worker': addr_backend_list,
                                  'worker -> sink': addr_sink,
                                  'ventilator <-> sink': addr_front2sink,
                                  'server_current_time': str(datetime.now()),
                                  'statistic': server_status.value,
                                  'device_map': device_map,
                                  'num_concurrent_socket': self.num_concurrent_socket}

A further look into server_status.value, it turns out class ServerStatistic has several Dict structures to store information and value property uses these structures to gather statistics, which leads to possible memory leaks and huge process time. My best guess: value property is the main cause of server performance downgrade.

>
class ServerStatistic:
def __init__(self):
self._hist_client = defaultdict(int)
self._hist_msg_len = defaultdict(int)
self._client_last_active_time = defaultdict(float)
self._num_data_req = 0
self._num_sys_req = 0
self._num_total_seq = 0
self._last_req_time = time.perf_counter()
self._last_two_req_interval = []
self._num_last_two_req = 200

def update(self, request):
    client, msg, req_id, msg_len = request
    self._hist_client[client] += 1
    if ServerCmd.is_valid(msg):
        self._num_sys_req += 1
        # do not count for system request, as they are mainly for heartbeats
    else:
        self._hist_msg_len[int(msg_len)] += 1
        self._num_total_seq += int(msg_len)
        self._num_data_req += 1
        tmp = time.perf_counter()
        self._client_last_active_time[client] = tmp
        if len(self._last_two_req_interval) < self._num_last_two_req:
            self._last_two_req_interval.append(tmp - self._last_req_time)
        else:
            self._last_two_req_interval.pop(0)
        self._last_req_time = tmp

@property
def value(self):
    def get_min_max_avg(name, stat):
        if len(stat) > 0:
            return {
                'avg_%s' % name: sum(stat) / len(stat),
                'min_%s' % name: min(stat),
                'max_%s' % name: max(stat),
                'num_min_%s' % name: sum(v == min(stat) for v in stat),
                'num_max_%s' % name: sum(v == max(stat) for v in stat),
            }
        else:
            return {}

    def get_num_active_client(interval=180):
        # we count a client active when its last request is within 3 min.
        now = time.perf_counter()
        return sum(1 for v in self._client_last_active_time.values() if (now - v) < interval)

    parts = [{
        'num_data_request': self._num_data_req,
        'num_total_seq': self._num_total_seq,
        'num_sys_request': self._num_sys_req,
        'num_total_request': self._num_data_req + self._num_sys_req,
        'num_total_client': len(self._hist_client),
        'num_active_client': get_num_active_client()},
        get_min_max_avg('request_per_client', self._hist_client.values()),
        get_min_max_avg('size_per_request', self._hist_msg_len.keys()),
        get_min_max_avg('last_two_interval', self._last_two_req_interval),
        get_min_max_avg('request_per_second', [1. / v for v in self._last_two_req_interval]),
    ]

    return {k: v for d in parts for k, v in d.items()}

Therefore, I just replaced server_status.value with an empty dictionary. After 30mins of continuous requests, performance is still good, which proves my guess. However BertClient will no longer have access to server status. I strongly recommend the author make a patch or something. I think this is a serious defect for this whole framework and a huge problem for anyone who wants to use this framework.

As my own code is in a corporate computer, it is impossible to copy paste the problem discovering + solving procedure. Wow, this is my first time to post an issue, and in English. Hope someone will fix this problem: both the performance and server status statistics

Source