Skip to content

swh-graph timeouts

This task is to investigate the number of timeouts generated by the swh-graph It seems it's not due to the number of parallel clients querying the graph in parallel as the exception are also raised for a unique client.

For example: The query:

http "http://granet:5009/graph/neighbors/swh:1:rev:bffd5ed1e4f1d784b670ec83bce630aee6a0a67d?edges=rev:rev&direction=forward&max_edges=0&return_types=rev"                                                                                                                                                                                                     09:54:19
HTTP/1.1 200 OK
Content-Type: text/plain
Date: Mon, 20 Jun 2022 07:54:21 GMT
Server: Python/3.7 aiohttp/3.6.2
Transfer-Encoding: chunked


http: error: ChunkedEncodingError: ("Connection broken: InvalidChunkLength(got length b'HTTP/1.1 500 Internal Server Error\\r\\n', 0 bytes read)", InvalidChunkLength(got length b'HTTP/1.1 500 Internal Server Error\r\n', 0 bytes read))

The swh-graph logs:

Jun 20 07:55:31 granet swh[59760]: ERROR:root:Exception is not set.
Jun 20 07:55:31 granet swh[59760]: Traceback (most recent call last):
Jun 20 07:55:31 granet swh[59760]:   File "/opt/swhgraph_venv/lib/python3.7/site-packages/swh/graph/backend.py", line 163, in java_call_iterator
Jun 20 07:55:31 granet swh[59760]:     async for value in reader:
Jun 20 07:55:31 granet swh[59760]:   File "/opt/swhgraph_venv/lib/python3.7/site-packages/swh/graph/backend.py", line 114, in read_node_ids
Jun 20 07:55:31 granet swh[59760]:     with (await asyncio.wait_for(open_thread, timeout=2)) as f:
Jun 20 07:55:31 granet swh[59760]:   File "/usr/lib/python3.7/asyncio/tasks.py", line 423, in wait_for
Jun 20 07:55:31 granet swh[59760]:     raise futures.TimeoutError()
Jun 20 07:55:31 granet swh[59760]: concurrent.futures._base.TimeoutError
Jun 20 07:55:31 granet swh[59760]: During handling of the above exception, another exception occurred:
Jun 20 07:55:31 granet swh[59760]: Traceback (most recent call last):
Jun 20 07:55:31 granet swh[59760]:   File "/opt/swhgraph_venv/lib/python3.7/site-packages/swh/core/api/asynchronous.py", line 71, in middleware_handler
Jun 20 07:55:31 granet swh[59760]:     return await handler(request)
Jun 20 07:55:31 granet swh[59760]:   File "/opt/swhgraph_venv/lib/python3.7/site-packages/aiohttp/web_urldispatcher.py", line 892, in _iter
Jun 20 07:55:31 granet swh[59760]:     resp = await method()
Jun 20 07:55:31 granet swh[59760]:   File "/opt/swhgraph_venv/lib/python3.7/site-packages/swh/graph/server/app.py", line 164, in get
Jun 20 07:55:31 granet swh[59760]:     await self.stream_response()
Jun 20 07:55:31 granet swh[59760]:   File "/opt/swhgraph_venv/lib/python3.7/site-packages/swh/graph/server/app.py", line 220, in stream_response
Jun 20 07:55:31 granet swh[59760]:     self.return_types,
Jun 20 07:55:31 granet swh[59760]:   File "/opt/swhgraph_venv/lib/python3.7/site-packages/swh/graph/backend.py", line 84, in traversal
Jun 20 07:55:31 granet swh[59760]:     async for line in method(*args):
Jun 20 07:55:31 granet swh[59760]:   File "/opt/swhgraph_venv/lib/python3.7/site-packages/swh/graph/backend.py", line 170, in java_call_iterator
Jun 20 07:55:31 granet swh[59760]:     task_exc = java_task.exception()
Jun 20 07:55:31 granet swh[59760]: asyncio.base_futures.InvalidStateError: Exception is not set.
Jun 20 07:55:31 granet swh[59760]: INFO:aiohttp.access:192.168.101.200 [20/Jun/2022:07:55:29 +0000] "GET /graph/neighbors/swh:1:rev:bffd5ed1e4f1d784b670ec83bce630aee6a0a67d?edges=rev:rev&direction=forward&max_edges=0&return_types=rev HTTP/1.1" 500 1960 "-" "HTTPie/2.2.0"

For information, these are the statistics of the queries done by the provenance clients:

root@granet:~# journalctl -u swhgraphdev.service | head -n1
-- Journal begins at Mon 2022-06-20 00:59:12 UTC, ends at Mon 2022-06-20 08:16:36 UTC. --
root@granet:~# journalctl -u swhgraphdev.service | grep " 500 " | wc -l
95453
root@granet:~# journalctl -u swhgraphdev.service | grep -v monitoring | grep " 200 " | wc -l
0
root@granet:~# journalctl -u swhgraphdev.service | grep " 400 " | wc -l
1875970

All the requests return a 500 or a 400

Migrated from T4340 (view on Phabricator)

Edited by Phabricator Migration user