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