[Technical Question] Sporadically getting ClientError: Unexpected failure when using invoke_method

[Maxime-Syc]

Hello,

My team and I use the method invocation feature of Azure IoT Edge and sporadically get the exception ClientError: Unexpected failure when using invoke_methode. It will run fine for multiple hours, then spontaniously throw the expection. You will find a stack trace bellow that, as far as I can tell, is the same everytime appart for which invocation throws the error.

Is there a reason why that error happens and, if yes, how can we mitigate it?

ERROR:concurrent.futures:exception calling callback for <Future at 0xffff583ab0d0 state=finished raised ClientError>
2025-02-26T01:09:42.276698242Z Traceback (most recent call last):
2025-02-26T01:09:42.276715138Z   File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 468, in _make_request
2025-02-26T01:09:42.276726337Z     six.raise_from(e, None)
2025-02-26T01:09:42.276735553Z   File "<string>", line 3, in raise_from
2025-02-26T01:09:42.276744993Z   File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 463, in _make_request
2025-02-26T01:09:42.276763296Z     httplib_response = conn.getresponse()
2025-02-26T01:09:42.276773248Z   File "/usr/local/lib/python3.10/http/client.py", line 1375, in getresponse
2025-02-26T01:09:42.276784352Z     response.begin()
2025-02-26T01:09:42.276792000Z   File "/usr/local/lib/python3.10/http/client.py", line 318, in begin
2025-02-26T01:09:42.276800320Z     version, status, reason = self._read_status()
2025-02-26T01:09:42.276808191Z   File "/usr/local/lib/python3.10/http/client.py", line 279, in _read_status
2025-02-26T01:09:42.276817407Z     line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
2025-02-26T01:09:42.276827327Z   File "/usr/local/lib/python3.10/socket.py", line 717, in readinto
2025-02-26T01:09:42.276836511Z     return self._sock.recv_into(b)
2025-02-26T01:09:42.276845502Z   File "/usr/local/lib/python3.10/ssl.py", line 1307, in recv_into
2025-02-26T01:09:42.276854302Z     return self.read(nbytes, buffer)
2025-02-26T01:09:42.276879806Z   File "/usr/local/lib/python3.10/ssl.py", line 1163, in read
2025-02-26T01:09:42.276938780Z     return self._sslobj.read(len, buffer)
2025-02-26T01:09:42.277131831Z TimeoutError: The read operation timed out
2025-02-26T01:09:42.277592012Z
2025-02-26T01:09:42.277931395Z During handling of the above exception, another exception occurred:
2025-02-26T01:09:42.278186333Z
2025-02-26T01:09:42.278471574Z Traceback (most recent call last):
2025-02-26T01:09:42.278740431Z   File "/usr/local/lib/python3.10/site-packages/requests/adapters.py", line 486, in send
2025-02-26T01:09:42.278917867Z     resp = conn.urlopen(
2025-02-26T01:09:42.279213283Z   File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 802, in urlopen
2025-02-26T01:09:42.279543323Z     retries = retries.increment(
2025-02-26T01:09:42.279903282Z   File "/usr/local/lib/python3.10/site-packages/urllib3/util/retry.py", line 552, in increment
2025-02-26T01:09:42.280198155Z     raise six.reraise(type(error), error, _stacktrace)
2025-02-26T01:09:42.280422117Z   File "/usr/local/lib/python3.10/site-packages/urllib3/packages/six.py", line 770, in reraise
2025-02-26T01:09:42.280741085Z     raise value
2025-02-26T01:09:42.280957304Z   File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 716, in urlopen
2025-02-26T01:09:42.281108052Z     httplib_response = self._make_request(
2025-02-26T01:09:42.281419276Z   File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 470, in _make_request
2025-02-26T01:09:42.281774499Z     self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
2025-02-26T01:09:42.281996062Z   File "/usr/local/lib/python3.10/site-packages/urllib3/connectionpool.py", line 358, in _raise_timeout
2025-02-26T01:09:42.282221720Z     raise ReadTimeoutError(
2025-02-26T01:09:42.282549072Z urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='p1135-aipc01', port=443): Read timed out. (read timeout=10)
2025-02-26T01:09:42.282786058Z
2025-02-26T01:09:42.283067331Z During handling of the above exception, another exception occurred:
2025-02-26T01:09:42.283349020Z
2025-02-26T01:09:42.283614965Z Traceback (most recent call last):
2025-02-26T01:09:42.283907566Z   File "/usr/local/lib/python3.10/site-packages/azure/iot/device/iothub/aio/async_clients.py", line 36, in handle_result
2025-02-26T01:09:42.284212678Z     return await callback.completion()
2025-02-26T01:09:42.284513727Z   File "/usr/local/lib/python3.10/site-packages/azure/iot/device/common/async_adapter.py", line 91, in completion
2025-02-26T01:09:42.284757529Z     return await self.future
2025-02-26T01:09:42.284939604Z   File "/usr/local/lib/python3.10/asyncio/futures.py", line 285, in __await__
2025-02-26T01:09:42.285235533Z     yield self  # This tells Task to wait for completion.
2025-02-26T01:09:42.285534821Z   File "/usr/local/lib/python3.10/asyncio/tasks.py", line 304, in __wakeup
2025-02-26T01:09:42.285731104Z     future.result()
2025-02-26T01:09:42.285975098Z   File "/usr/local/lib/python3.10/asyncio/futures.py", line 201, in result
2025-02-26T01:09:42.286234804Z     raise self._exception.with_traceback(self._exception_tb)
2025-02-26T01:09:42.286541420Z   File "/usr/local/lib/python3.10/site-packages/azure/iot/device/common/http_transport.py", line 138, in request
2025-02-26T01:09:42.286895203Z     response = session.post(
2025-02-26T01:09:42.287209467Z   File "/usr/local/lib/python3.10/site-packages/requests/sessions.py", line 637, in post
2025-02-26T01:09:42.287532179Z     return self.request("POST", url, data=data, json=json, **kwargs)
2025-02-26T01:09:42.287732558Z   File "/usr/local/lib/python3.10/site-packages/requests/sessions.py", line 589, in request
2025-02-26T01:09:42.288025415Z     resp = self.send(prep, **send_kwargs)
2025-02-26T01:09:42.288241633Z   File "/usr/local/lib/python3.10/site-packages/requests/sessions.py", line 703, in send
2025-02-26T01:09:42.288558201Z     r = adapter.send(request, **kwargs)
2025-02-26T01:09:42.288860242Z   File "/usr/local/lib/python3.10/site-packages/requests/adapters.py", line 532, in send
2025-02-26T01:09:42.289061037Z     raise ReadTimeout(e, request=request)
2025-02-26T01:09:42.289270728Z requests.exceptions.ReadTimeout: HTTPSConnectionPool(host='p1135-aipc01', port=443): Read timed out. (read timeout=10)
2025-02-26T01:09:42.289448739Z
2025-02-26T01:09:42.289699837Z The above exception was the direct cause of the following exception:
2025-02-26T01:09:42.290151474Z
2025-02-26T01:09:42.290463178Z Traceback (most recent call last):
2025-02-26T01:09:42.290800705Z   File "/usr/local/lib/python3.10/concurrent/futures/_base.py", line 342, in _invoke_callbacks
2025-02-26T01:09:42.291069915Z     callback(self)
2025-02-26T01:09:42.291410578Z   File "/app/service/service.py", line 146, in return_results
2025-02-26T01:09:42.291624557Z     results: tuple[Any, ...] = results_future.result()
2025-02-26T01:09:42.291885958Z   File "/usr/local/lib/python3.10/concurrent/futures/_base.py", line 451, in result
2025-02-26T01:09:42.292170655Z     return self.__get_result()
2025-02-26T01:09:42.292344699Z   File "/usr/local/lib/python3.10/concurrent/futures/_base.py", line 403, in __get_result
2025-02-26T01:09:42.292666003Z     raise self._exception
2025-02-26T01:09:42.293013610Z   File "/usr/local/lib/python3.10/asyncio/tasks.py", line 234, in __step
2025-02-26T01:09:42.293272612Z     result = coro.throw(exc)
2025-02-26T01:09:42.293495742Z   File "/app/service/action/robot/robot_auto_prod.py", line 1203, in exec
2025-02-26T01:09:42.293712313Z     if (await self.go_multi_capture(capture_id)) != 0:
2025-02-26T01:09:42.293956850Z   File "/app/service/action/robot/robot_auto_prod.py", line 592, in go_multi_capture
2025-02-26T01:09:42.294282698Z     scode = await self.go_capture(pose_id, capture_id)
2025-02-26T01:09:42.294548484Z   File "/app/service/action/robot/robot_auto_prod.py", line 634, in go_capture
2025-02-26T01:09:42.294953594Z     done = await self.vision_capture(capture_id, flange_pose.to_dict())
2025-02-26T01:09:42.295203443Z   File "/app/service/action/robot/robot_auto_prod.py", line 541, in vision_capture
2025-02-26T01:09:42.295400270Z     done = await self._vision_proxy.capture(capture_id, tcp_pose)
2025-02-26T01:09:42.295651272Z   File "/app/service/proxy/vision_proxy.py", line 172, in capture
2025-02-26T01:09:42.295846691Z     res = await self._client.invoke_method(
2025-02-26T01:09:42.296140092Z   File "/usr/local/lib/python3.10/site-packages/azure/iot/device/iothub/aio/async_clients.py", line 714, in invoke_method
2025-02-26T01:09:42.296421525Z     method_response = await handle_result(callback)
2025-02-26T01:09:42.296737197Z   File "/usr/local/lib/python3.10/site-packages/azure/iot/device/iothub/aio/async_clients.py", line 60, in handle_result
2025-02-26T01:09:42.297029222Z     raise exceptions.ClientError("Unexpected failure") from e
2025-02-26T01:09:42.297291999Z azure.iot.device.exceptions.ClientError: Unexpected failure