handle BNL people API query problems better #135
Description
The following problem seems to occur at times when multiple nsls2api synchronizing jobs are running. PR #134 handles in the most basic way by logging and returning a None value, but a better solution should be found long-term.
[2025-01-23T13:24:42.432Z] [5f89b0c771354d35] INFO: 10.65.3.167:40348 - "GET /healthy HTTP/1.1" 200 OK
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.475Z] [-] WARNING: BNL People could not find a person with an employee/life number of '4569B'
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.476Z] [-] INFO: Received SIGTERM, exiting.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.477Z] [-] INFO: Terminated child process [7]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.477Z] [-] INFO: Terminated child process [8]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.477Z] [-] INFO: Terminated child process [9]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.477Z] [-] INFO: Terminated child process [10]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.477Z] [-] INFO: Waiting for child process [7]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.487Z] [-] INFO: Shutting down
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.515Z] [-] INFO: Shutting down
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.532Z] [-] WARNING: BNL People could not find a person with an employee/life number of '4748B'
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.552Z] [-] INFO: Shutting down
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.553Z] [-] INFO: Shutting down
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.588Z] [-] INFO: Waiting for application shutdown.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.588Z] [-] INFO: HTTPXClientWrapper [140632962411808] stopped.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.590Z] [-] INFO: Application shutdown complete.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.590Z] [-] INFO: Finished server process [7]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.598Z] [-] INFO: Waiting for child process [8]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.616Z] [-] INFO: Waiting for application shutdown.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.616Z] [-] INFO: HTTPXClientWrapper [140217254930928] stopped.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.617Z] [-] ERROR: Error processing job 679221a0e2b757a1b1329933 for synchronize_proposals_for_cycle:
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: Traceback (most recent call last):
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpx/_transports/default.py", line 101, in map_httpcore_exceptions
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: yield
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpx/_transports/default.py", line 394, in handle_async_request
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: resp = await self._pool.handle_async_request(req)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpcore/_async/connection_pool.py", line 256, in handle_async_request
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: raise exc from None
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpcore/_async/connection_pool.py", line 236, in handle_async_request
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: response = await connection.handle_async_request(
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpcore/_async/connection.py", line 103, in handle_async_request
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: return await self._connection.handle_async_request(request)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpcore/_async/http11.py", line 136, in handle_async_request
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: raise exc
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpcore/_async/http11.py", line 106, in handle_async_request
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ) = await self._receive_response_headers(**kwargs)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpcore/_async/http11.py", line 177, in _receive_response_headers
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: event = await self._receive_event(timeout=timeout)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpcore/_async/http11.py", line 217, in _receive_event
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: data = await self._network_stream.read(
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpcore/_backends/anyio.py", line 32, in read
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: with map_exceptions(exc_map):
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/contextlib.py", line 158, in __exit__
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: self.gen.throw(value)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpcore/_exceptions.py", line 14, in map_exceptions
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: raise to_exc(exc) from exc
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: httpcore.ReadError
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]:
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: The above exception was the direct cause of the following exception:
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]:
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: Traceback (most recent call last):
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/nsls2api/services/background_service.py", line 135, in worker_function
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: await sync_service.worker_synchronize_proposals_for_cycle_from_pass(
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/nsls2api/services/sync_service.py", line 389, in worker_synchronize_proposals_for_cycle_from_pass
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: await synchronize_proposal_from_pass(proposal_id, facility_name)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/nsls2api/services/sync_service.py", line 264, in synchronize_proposal_from_pass
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: bnl_username = await bnlpeople_service.get_username_by_id(user.BNL_ID)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/nsls2api/services/bnlpeople_service.py", line 38, in get_username_by_id
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: person = await _call_bnlpeople_webservice(url)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/nsls2api/services/bnlpeople_service.py", line 13, in _call_bnlpeople_webservice
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: return await _call_async_webservice_with_client(url, client=httpx_client_wrapper())
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/nsls2api/services/helpers.py", line 70, in _call_async_webservice_with_client
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: resp: Response = await client.get(url, timeout=90.0, auth=auth, headers=headers)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1768, in get
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: return await self.request(
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1540, in request
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: return await self.send(request, auth=auth, follow_redirects=follow_redirects)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1629, in send
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: response = await self._send_handling_auth(
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1657, in _send_handling_auth
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: response = await self._send_handling_redirects(
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1694, in _send_handling_redirects
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: response = await self._send_single_request(request)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpx/_client.py", line 1730, in _send_single_request
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: response = await transport.handle_async_request(request)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpx/_transports/default.py", line 393, in handle_async_request
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: with map_httpcore_exceptions():
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: ^^^^^^^^^^^^^^^^^^^^^^^^^
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/contextlib.py", line 158, in __exit__
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: self.gen.throw(value)
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: File "/usr/local/lib/python3.12/site-packages/httpx/_transports/default.py", line 118, in map_httpcore_exceptions
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: raise mapped_exc(message) from exc
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: httpx.ReadError
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.624Z] [-] INFO: Application shutdown complete.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.624Z] [-] INFO: Finished server process [8]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.631Z] [-] INFO: Waiting for child process [9]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.653Z] [-] INFO: Waiting for application shutdown.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.653Z] [-] INFO: HTTPXClientWrapper [140237099284960] stopped.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.654Z] [-] INFO: Application shutdown complete.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.654Z] [-] INFO: Finished server process [9]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.654Z] [-] INFO: Waiting for application shutdown.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.654Z] [-] INFO: HTTPXClientWrapper [140594165674112] stopped.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.656Z] [-] INFO: Application shutdown complete.
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.656Z] [-] INFO: Finished server process [10]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.660Z] [-] INFO: Waiting for child process [10]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov nsls2api[1707993]: [2025-01-23T13:24:42.663Z] [-] INFO: Stopping parent process [1]
Jan 23 08:24:42 api-dev1.nsls2.bnl.gov podman[1917538]: 5960fed7253e7d8f8fc9ae716aaef555a688ee5dcd8706355097709e4b8f3475