Incident on prod: too many open files

EPIC: #512

Description

Uptime robot sent e-mail alerts the night of 2019-10-24.

Several errors were spotted in /var/log/uwsgi/app/dbnomics-api-uwsgi-v22.log.1.

First analysis

"too many open files" error results in the incapacity for the system to initiate a new HTTP request, whatever the target is (Solr, Matomo, etc.). So the problem is not related to Solr in particular.

Questions

was the previous incident about "Solr max retries" caused by "too many open files" too?

Tasks

monitor the number of open files
- versus the max number of open files
- for each server, at least dolos and eros
- by process
understand which process took so many open files

Error log excerpts

ERROR:flask.app:Exception on /series/BEA/NIPA-T20304/DDURRG-A [GET]
Traceback (most recent call last):
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/app.py", line 2292, in wsgi_app
    response = self.full_dispatch_request()
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/app.py", line 1815, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask_cors/extension.py", line 161, in wrapped_function
    return cors_after_request(app.make_response(f(*args, **kwargs)))
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/app.py", line 1718, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/_compat.py", line 35, in reraise
    raise value
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/app.py", line 1813, in full_dispatch_request
    rv = self.dispatch_request()
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/app.py", line 1799, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flasgger/utils.py", line 248, in wrapper
    return function(*args, **kwargs)
  File "/home/cepremap/dbnomics-api-v22/dbnomics-api/dbnomics_api/route_handlers.py", line 332, in series_of_dataset
    dataset_json = storages.load_dataset_json_or_abort(404, args, storage, dataset_code, dataset_dir)
  File "/home/cepremap/dbnomics-api-v22/dbnomics-api/dbnomics_api/storages.py", line 55, in load_dataset_json_or_abort
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dbnomics_data_model/storages/abstract.py", line 222, in load_dataset_json
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dbnomics_data_model/storages/git.py", line 146, in _load_dataset_json
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dbnomics_data_model/storages/git.py", line 164, in tree
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dbnomics_data_model/storages/git.py", line 234, in load_tree
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dulwich/repo.py", line 627, in __getitem__
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dulwich/object_store.py", line 120, in __getitem__
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dulwich/object_store.py", line 462, in get_raw
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dulwich/pack.py", line 2000, in get_raw
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dulwich/pack.py", line 1923, in index
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dulwich/pack.py", line 1883, in <lambda>
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dulwich/pack.py", line 281, in load_pack_index
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/dulwich/file.py", line 90, in GitFile
OSError: [Errno 24] Too many open files: '/home/gitlab-runner/json-data/bea-json-data.git/objects/pack/pack-38adbcac21ff62d5a657591b625eb4822a30d1df.idx'
[pid: 6475|app: 0|req: 76367/685447] 163.172.179.200 () {40 vars in 584 bytes} [Wed Oct 23 23:39:03 2019] GET /v22/series/BEA/NIPA-T20304/DDURRG-A?observations=1 => generated 64 bytes in 26 msecs (HTTP/1.1 500) 3 headers in 122 bytes (1 switches on core 1)

ERROR:flask.app:Exception on /series/Eurostat/tet00063/A.EXT_EU28.SITC0_1.CONT_EXP_EU.LU [GET]
Traceback (most recent call last):
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connection.py", line 159, in _new_conn
    (self._dns_host, self.port), self.timeout, **extra_kw)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/util/connection.py", line 80, in create_connection
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/util/connection.py", line 61, in create_connection
  File "/usr/lib/python3.5/socket.py", line 134, in __init__
OSError: [Errno 24] Too many open files

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connectionpool.py", line 600, in urlopen
    chunked=chunked)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connectionpool.py", line 354, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/lib/python3.5/http/client.py", line 1107, in request
    self._send_request(method, url, body, headers)
  File "/usr/lib/python3.5/http/client.py", line 1152, in _send_request
    self.endheaders(body)
  File "/usr/lib/python3.5/http/client.py", line 1103, in endheaders
    self._send_output(message_body)
  File "/usr/lib/python3.5/http/client.py", line 934, in _send_output
    self.send(msg)
  File "/usr/lib/python3.5/http/client.py", line 877, in send
    self.connect()
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connection.py", line 181, in connect
    conn = self._new_conn()
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connection.py", line 168, in _new_conn
    self, "Failed to establish a new connection: %s" % e)
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f24a03a56a0>: Failed to establish a new connection: [Errno 24] Too many open files

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connectionpool.py", line 638, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/util/retry.py", line 398, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='localhost', port=8983): Max retries exceeded with url: /solr/dbnomics/query (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f24a03a56a0>: Failed to establish a new connection: [Errno 24] Too many open files',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/app.py", line 2292, in wsgi_app
    response = self.full_dispatch_request()
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/app.py", line 1815, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask_cors/extension.py", line 161, in wrapped_function
    return cors_after_request(app.make_response(f(*args, **kwargs)))
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/app.py", line 1718, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/_compat.py", line 35, in reraise
    raise value
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/app.py", line 1813, in full_dispatch_request
    rv = self.dispatch_request()
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask/app.py", line 1799, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flasgger/utils.py", line 248, in wrapper
    return function(*args, **kwargs)
  File "/home/cepremap/dbnomics-api-v22/dbnomics-api/dbnomics_api/route_handlers.py", line 321, in series_of_dataset
    provider_solr = solr.get_provider(provider_code)
  File "/home/cepremap/dbnomics-api-v22/dbnomics-api/dbnomics_api/solr.py", line 190, in get_provider
    "limit": 1,
  File "/home/cepremap/dbnomics-api-v22/dbnomics-api/dbnomics_api/solr.py", line 230, in solr_request
    response = requests.post(solr_query_url, json=new_json_payload)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/api.py", line 116, in post
    return request('post', url, data=data, json=json, **kwargs)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/adapters.py", line 516, in send
    raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='localhost', port=8983): Max retries exceeded with url: /solr/dbnomics/query (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7f24a03a56a0>: Failed to establish a new connection: [Errno 24] Too many open files',))
[pid: 6475|app: 0|req: 76368/685448] 163.172.179.200 () {40 vars in 638 bytes} [Wed Oct 23 23:39:03 2019] GET /v22/series/Eurostat/tet00063/A.EXT_EU28.SITC0_1.CONT_EXP_EU.LU?observations=1 => generated 64 bytes in 11 msecs (HTTP/1.1 500) 3 headers in 122 bytes (1 switches on core 0)

Exception in thread Thread-76370:
Traceback (most recent call last):
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/util/ssl_.py", line 321, in ssl_wrap_socket
    context.load_verify_locations(ca_certs, ca_cert_dir)
OSError: [Errno 24] Too many open files

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connectionpool.py", line 600, in urlopen
    chunked=chunked)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connectionpool.py", line 343, in _make_request
    self._validate_conn(conn)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connectionpool.py", line 839, in _validate_conn
    conn.connect()
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connection.py", line 344, in connect
    ssl_context=context)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/util/ssl_.py", line 323, in ssl_wrap_socket
    raise SSLError(e)
urllib3.exceptions.SSLError: [Errno 24] Too many open files

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/connectionpool.py", line 638, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/urllib3/util/retry.py", line 398, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='analytics.nomics.world', port=443): Max retries exceeded with url: /piwik.php?cip=163.172.179.200&idsite=3&token_auth=secret&action_name=series_of_dataset&rec=1&ua=node-fetch%2F1.0+%28%2Bhttps%3A%2F%2Fgithub.com%2Fbitinn%2Fnode-fetch%29&url=https%3A%2F%2Fapi.db.nomics.world%2Fv22%2Fseries%2FNBS%2FA_A0S0H03%2FA0S0H030O%3Fobservations%3D1 (Caused by SSLError(OSError(24, 'Too many open files'),))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.5/threading.py", line 914, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.5/threading.py", line 862, in run
    self._target(*self._args, **self._kwargs)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/flask_matomo/core.py", line 100, in track
    r = requests.post(self.matomo_url + "/piwik.php", params=data)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/api.py", line 116, in post
    return request('post', url, data=data, json=json, **kwargs)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/api.py", line 60, in request
    return session.request(method=method, url=url, **kwargs)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "/home/cepremap/virtualenvs/dbnomics-api-v22/lib/python3.5/site-packages/requests/adapters.py", line 514, in send
    raise SSLError(e, request=request)
requests.exceptions.SSLError: HTTPSConnectionPool(host='analytics.nomics.world', port=443): Max retries exceeded with url: /piwik.php?cip=163.172.179.200&idsite=3&token_auth=secret&action_name=series_of_dataset&rec=1&ua=node-fetch%2F1.0+%28%2Bhttps%3A%2F%2Fgithub.com%2Fbitinn%2Fnode-fetch%29&url=https%3A%2F%2Fapi.db.nomics.world%2Fv22%2Fseries%2FNBS%2FA_A0S0H03%2FA0S0H030O%3Fobservations%3D1 (Caused by SSLError(OSError(24, 'Too many open files'),))

Edited Oct 25, 2019 by Christophe Benz